Re: pgbench rate limiting changes transaction latency computation

Hi

On 2019-06-10 21:56:31 -0700, Andres Freund wrote:
> I noticed that pgbench's -R influences not just the computation of lag,
> but also of latency. That doesn't look right to me, but maybe I'm just
> missing something?

I apparently did:

> -P sec
> --progress=sec
>
> Show progress report every sec seconds. The report includes the time
> since the beginning of the run, the TPS since the last report, and
> the transaction latency average and standard deviation since the
> last report. Under throttling (-R), the latency is computed with
> respect to the transaction scheduled start time, not the actual
> transaction beginning time, thus it also includes the average
> schedule lag time.

But that makes very little sense to me. I see that was changed by Heikki
in

https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=02e3bcc661598275a75a8649b48602dca7aeec79
> Change the way latency is calculated with pgbench --rate option.
>
> The reported latency values now include the "schedule lag" time, that is,
> the time between the transaction's scheduled start time and the time it
> actually started. This relates better to a model where requests arrive at a
> certain rate, and we are interested in the response time to the end user or
> application, rather than the response time of the database itself.
>
> Also, when --rate is used, include the schedule lag time in the log output.
>
> The --rate option is new in 9.4, so backpatch to 9.4. It seems better to
> make this change in 9.4, while we're still in the beta period, than ship a
> 9.4 version that calculates the values differently than 9.5.

I find that pretty unconvincing. Report a new field, sure. But what's
the point of changing an *established* field, just due to rate limiting?
At the very least that ought to commented upon in the code as well.

Doesn't this mean that latency and lag are quite redundant, just more
obscure, due this change?

latency = INSTR_TIME_GET_MICROSEC(*now) - st->txn_scheduled;
lag = INSTR_TIME_GET_MICROSEC(st->txn_begin) - st->txn_scheduled;

I guess I can just subtract latency from lag to get to the non-throttled
latency. But that is, uh, odd.

Greetings,

Andres Freund