Re: pgbench throttling latency limit

On 09/15/2014 08:46 PM, Fabien COELHO wrote:
>
>> I'm not sure I like the idea of printing a percentage. It might be
>> unclear what the denominator was if somebody feels the urge to work
>> back to the actual number of skipped transactions. I mean, I guess
>> it's probably just the value you passed to -R, so maybe that's easy
>> enough, but then why bother dividing in the first place? The user can
>> do that easily enough if they want the data that way.
>
> Indeed "skipped" and "late" per second may have an unclear denominator. If
> you divide by the time, the unit would be "tps", but 120 tps performance
> including 20 late tps, plus 10 skipped tps... I do not think it is that
> clear. Reporting "tps" for transaction *not* performed looks strange.
>
> Maybe late transactions could be given as a percentage of all processed
> transactions in the interval. But for skipped the percentage of what? The
> only number that would make sense is the total number of transactions
> schedule in the interval, but that would mean that the denominator for
> late would be different than the denominator for skipped, which is
> basically uncomprehensible.

Hmm. I guess the absolute number makes sense, if you expect that there
are normally zero skipped transactions, or at least a very small number.
It's more like a "good or no good" indicator. Ok, I'm fine with that.

The version I'm now working on prints output like this:

> $ ./pgbench -T10 -P1 --rate=1600 --latency-limit=10
> starting vacuum...end.
> progress: 1.0 s, 1579.0 tps, lat 2.973 ms stddev 2.493, lag 2.414 ms, 4 skipped
> progress: 2.0 s, 1570.0 tps, lat 2.140 ms stddev 1.783, lag 1.599 ms, 0 skipped
> progress: 3.0 s, 1663.0 tps, lat 2.372 ms stddev 1.742, lag 1.843 ms, 4 skipped
> progress: 4.0 s, 1603.2 tps, lat 2.435 ms stddev 2.247, lag 1.902 ms, 13 skipped
> progress: 5.0 s, 1540.9 tps, lat 1.845 ms stddev 1.270, lag 1.303 ms, 0 skipped
> progress: 6.0 s, 1588.0 tps, lat 1.630 ms stddev 1.003, lag 1.097 ms, 0 skipped
> progress: 7.0 s, 1577.0 tps, lat 2.071 ms stddev 1.445, lag 1.517 ms, 0 skipped
> progress: 8.0 s, 1669.9 tps, lat 2.375 ms stddev 1.917, lag 1.846 ms, 0 skipped
> progress: 9.0 s, 1636.0 tps, lat 2.801 ms stddev 2.354, lag 2.250 ms, 5 skipped
> progress: 10.0 s, 1606.1 tps, lat 2.751 ms stddev 2.117, lag 2.197 ms, 2 skipped
> transaction type: TPC-B (sort of)
> scaling factor: 5
> query mode: simple
> number of clients: 1
> number of threads: 1
> duration: 10 s
> number of transactions actually processed: 16034
> number of transactions skipped: 28 (0.174 %)
> number of transactions above the 10.0 ms latency limit: 70 (0.436 %)
> latency average: 2.343 ms
> latency stddev: 1.940 ms
> rate limit schedule lag: avg 1.801 (max 9.994) ms
> tps = 1603.370819 (including connections establishing)
> tps = 1603.619536 (excluding connections establishing)

Those progress lines are 79 or 80 characters wide, so they *just* fit in
a 80-char terminal. Of course, if any of the printed numbers were
higher, it would not fit. I don't see how to usefully make it more
terse, though. I think we can live with this - these days it shouldn't
be a huge problem to enlare the terminal to make the output fit.

Here are new patches, again the first one is just refactoring, and the
second one contains this feature. I'm planning to commit the first one
shortly, and the second one later after people have had a chance to look
at it.

Greg: As the author of pgbench-tools, what do you think of this patch?
The log file format, in particular.

- Heikki