Re: pg_test_timing: fix unit typo and widen diff type

Hi Chao,

On Wed, Apr 1, 2026 at 8:10 PM Chao Li <li(dot)evan(dot)chao(at)gmail(dot)com> wrote:
>
> Hi,
>
> This morning, as part of my usual routine, I synced the master branch and read through the recent commits. While reading 82c0cb4e672, I noticed a mistake in an error message. The relevant code is like:
> ```
> diff = INSTR_TIME_GET_NANOSEC(diff_time);
>
> fprintf(stderr, _("Time warp: %d ms\n"), diff);
> ```
>
> Here, “diff" is in nanoseconds, but the error message prints ms as the unit, which is incorrect.

Good catch!

It looks like the use of nanoseconds for "diff" got introduced last
year in 0b096e379e6f9bd49 (as you note later in the email, today's
commit didn't actually change that part), CCing Tom and Hannu as
authors of that earlier change.

That said, its a bit odd that we were using INSTR_TIME_GET_MICROSEC
there before that earlier commit, but called it "ms" (i.e.
milliseconds) in the error message.

>
> To fix that, I think there are two possible options:
>
> 1. Use INSTR_TIME_GET_MILLISEC to get “diff"
> 2. Change “ms" to “ns" in the error message
>
> After reading through the whole file, I think option 2 is the right fix. While doing that, I also noticed another issue.
>
> “diff" is currently defined as int32. Although one might think that is enough for a time delta, I believe it should be int64 for two reasons:
>
> * INSTR_TIME_GET_NANOSEC() explicitly returns int64:
> ```
> #define INSTR_TIME_GET_NANOSEC(t) \
> ((int64) (t).ticks)
> ```
>
> * The current code has a sanity check for backward clock drift:
> ```
> /* Did time go backwards? */
> if (unlikely(diff < 0))
> {
> fprintf(stderr, _("Detected clock going backwards in time.\n"));
> fprintf(stderr, _("Time warp: %d ms\n"), diff);
> exit(1);
> }
> ```
> Clock jumping forward is also possible, and a forward jump of about 2.14 seconds would overflow int32 when expressed in nanoseconds, making the value appear negative. In that case, the code could report a “backwards” clock jump when the actual jump was forwards, which would be misleading.

I agree it doesn't seem sound to use an int32 for storing the result
of INSTR_TIME_GET_NANOSEC. It looks like we may also need to adjust
the call to pg_leftmost_one_pos32 though if we actually accept that
large a "diff" value, as in your patch.

Maybe we should error out if the diff is larger than an int32, noting
a positive time drift?

Independently of that, its worth noting we could easily emit the diff
in a larger unit (micro or milliseconds) for easier interpretation, by
just calling INSTR_TIME_GET_MICROSEC / INSTR_TIME_GET_MILLISEC on the
"diff_time" again.

Thanks,
Lukas

--
Lukas Fittl