Re: PATCH: pgbench - merging transaction logs

Hello Tomas,

>> My point is that if there are many threads and tremendous TPS, the
>> *detailed* per-transaction log (aka simple log) is probably a bad
>> choice anyway, and the aggregated version is the way to go.
>
> I disagree with this reasoning. Can you provide numbers supporting it?

I'm not sure which part of this reasoning you want me to support with 
numbers.

My first argument is qualitative: I'm trying to say that if you are doing 
100000 tps, probably the per-transaction detailed measure would be useless 
as such, so there is no point in logging them all. You would rather be 
interested in aggregate figures and should also be interested in extremal 
events (very slow queries) and their frequency.

The second point is that aggregated logs should be cheaper than detailed 
log, it seems more or less self evident to me.

> I do agree that fprintf is not cheap, actually when profiling pgbench
> it's often the #1 item, but the impact on the measurements is actually
> quite small. For example with a small database (scale 10) and read-only
> 30-second runs (single client), I get this:
>
>   no logging: 18672 18792 18667 18518 18613 18547
> with logging: 18170 18093 18162 18273 18307 18234
>
> So on average, that's 18634 vs. 18206, i.e. less than 2.5% difference.
> And with more expensive transactions (larger scale, writes, ...) the
> difference will be much smaller.

Ok. Great!

Let us take this as a worst-case figure and try some maths.

If fprintf takes p = 0.025 (1/40) of the time, then with 2 threads the 
collision probability would be about 1/40 and the delayed thread would be 
waiting for half this time on average, so the performance impact due to 
fprintf locking would be negligeable (1/80 delay occured in 1/40 cases => 
1/3200 time added on the computed average, if I'm not mistaken).

With t threads, I would guess that the collision probability in the first 
order is about 0.5 t (t-1) p, and the performance impact would be ~ (0.5 t 
(t-1) p * 0.5 p) (hmmm... this approximation, if not completely stupid, 
just holds for small p and not too large t).

With your worst-case figure and some rounding, it seems to look like:
  #threads    collision probability    performance impact    2             1/40                    1/3200    4
  1/7                     1/533    8             0.7                     < 0.01 (about 1%)
 

This suggest that for a pessimistic (ro load) fprintf overhead ratio there 
would be a small impact even with 8 thread doing 20000 tps each.

> It's true that this might produce large logs, especially when the runs
> are long, but that has nothing to do with fprintf. And can be easily
> fixed by either using a dedicated client machine, or only sample the
> transaction log.

Sure. In which case locking/mutex is not an issue.

> Introducing actual synchronization between the threads (by locking
> inside fprintf) is however a completely different thing.

It is the issue I'm trying to discuss.

>> Note that even without mutex fprintf may be considered a "heavy
>> function" which is going to slow down the transaction rate
>> significantly. That could be tested as well.
>>
>> It is possible to reduce the lock time by preparing the string
>> (which would mean introducing buffers) and just do a "fputs" under
>> mutex. That would not reduce the print time anyway, and that may add
>> malloc/free operations, though.
>
> I seriously doubt fprintf does the string formatting while holding lock
> on the file.

I do not think that the lock is necessarily at the file (OS level), but at 
least it has to hold the FILE structure to manage buffering without 
interference from other threads during string processing and printing.

> So by doing this you only simulate what fprintf() does (assuming it's 
> thread-safe on your platform) and gain nothing.

Ok, if fprintf is thread safe, I fully agree that there is no need to add 
a mutex or lock! However I do not know how to test that, so putting a 
useless mutex would prevent

>>> The way to know if there's a real problem here is to test it, but
>>> I'd be pretty surprised if there isn't.
>>
>> Indeed, I think I can contrive a simple example where it is,
>> basically a more or less empty or read only transaction (eg SELECT
>> 1).
>
> That would be nice, because my quick testing suggests it's not the case.

I do not understand your point. ISTM that your test and my maths suggest
that the performance impact of the fprintf approach is reasonably low.

>> My opinion is that there is a tradeoff between code simplicity and
>> later maintenance vs feature benefit.
>>
>> If threads are assumed and fprintf is used, the feature is much
>> simpler to implement, and the maintenance is lighter.
>
> I think the "if threads are assumed" part makes this dead in water
> unless someone wants to spend time on getting rid of the thread
> emulation.

My suggestion is to skip the feature under thread emulation, not 
necessarily to remove thread emulation, because of the argument you raise 
below.

> Removing the code is quite simple, researching whether we can do that 
> will be difficult IMHO - I have no idea which of the supported platorms 
> require the emulation etc.

I know of none, that is a start:-)

> And I envision endless discussions about this.

You are pessimistic, it may be a very quick and emphatic "NO":-)

>> The alternative implementation means reparsing the generated files
>> over and over for merging their contents.
>
> I agree that the current implementation is not particularly pretty, and
> I plan to get rid of the copy&paste parts etc.

That would be good.

>> Also, I do not think that the detailed log provides much benefit
>> with very fast transactions, where probably the aggregate is a much
>> better choice anyway. If the user persists, she may generate a
>> per-thread log and merge it later, in which case a merge script is
>> needed, but I do not think that would be a bad thing.
>
> I disagree with this - I use transaction logs (either complete or
> sampled) quite often. I also explained why I think a separate merge
> script is awkward to use.

Yes, I did read that, but for me the choice is between an "awkward" script 
outside or "awkward" code inside to maintain forever, hence my lack of 
enthousiasm and the sought for a lighter solution.

Note that "sampled" would have no locking issue, because the overhead is 
very low.

Just for the record I do not like simplistic samples because they would 
miss infrequent large events (eg if 1/40000 transaction takes 40000 more 
time to be processed, it counts for half the time, it divides the 
performance by 2, and you will not get it often in your sample).

-- 
Fabien.