public inbox for [email protected]
help / color / mirror / Atom feedFrom: Chao Li <[email protected]>
To: Lukas Fittl <[email protected]>
Cc: PostgreSQL Hackers <[email protected]>
Cc: Tom Lane <[email protected]>
Cc: Hannu Krosing <[email protected]>
Subject: Re: pg_test_timing: fix unit typo and widen diff type
Date: Wed, 8 Apr 2026 12:06:07 +0800
Message-ID: <[email protected]> (raw)
In-Reply-To: <[email protected]>
References: <[email protected]>
<CAP53PkwEZ+UMmwA8cbUSUdE6phXi+xWmn5t-YAnvKf0qoBnOvg@mail.gmail.com>
<[email protected]>
> On Apr 2, 2026, at 15:28, Chao Li <[email protected]> wrote:
>
>
>
>> On Apr 2, 2026, at 12:17, Lukas Fittl <[email protected]> wrote:
>>
>> Hi Chao,
>>
>> On Wed, Apr 1, 2026 at 8:10 PM Chao Li <[email protected]> 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.
>
> You are right. Changed to pg_leftmost_one_pos64 in v2.
>
>>
>> Maybe we should error out if the diff is larger than an int32, noting
>> a positive time drift?
>
> I agree we should warn/fail upon clock forwards drift. But I doubt int32 is too big (~2.14 seconds), I consider 1 second could be a too big threshold. Let’s wait for more voices on this.
>
>>
>> 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.
>>
>
> Given the error should rarely happen, I personally feel that might not be super helpful. Also, if the drift is just beyond the threshold, bumping to microsecond or millisecond might print just 0.
>
> PFA v2 - updated 0002 for pg_leftmost_one_pos64.
>
> Best regards,
> --
> Chao Li (Evan)
> HighGo Software Co., Ltd.
> https://www.highgo.com/
>
>
>
>
> <v2-0001-pg_test_timing-fix-unit-in-backward-clock-warning.patch><v2-0002-pg_test_timing-use-int64-for-largest-observed-tim.patch>
PFA v3: Fixed a CI failure.
Best regards,
--
Chao Li (Evan)
HighGo Software Co., Ltd.
https://www.highgo.com/
Attachments:
[application/octet-stream] v3-0001-pg_test_timing-fix-unit-in-backward-clock-warning.patch (1.3K, 2-v3-0001-pg_test_timing-fix-unit-in-backward-clock-warning.patch)
download | inline diff:
From 0b4419bd6318f29a56ec263de7d4be042b55a6d8 Mon Sep 17 00:00:00 2001
From: "Chao Li (Evan)" <[email protected]>
Date: Thu, 2 Apr 2026 10:21:40 +0800
Subject: [PATCH v3 1/2] pg_test_timing: fix unit in backward-clock warning
pg_test_timing measures timing differences in nanoseconds via
INSTR_TIME_GET_NANOSEC(), but the backward-clock warning incorrectly
reported the value as milliseconds. Fix the message to use "ns" so
that it matches the actual unit of diff.
Author: Chao Li <[email protected]>
Reviewed-by: Lukas Fittl <[email protected]>
Discussion: https://postgr.es/m/[email protected]
---
src/bin/pg_test_timing/pg_test_timing.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index 2afb0e6a410..944b25df1f2 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -281,7 +281,7 @@ test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timin
if (unlikely(diff < 0))
{
fprintf(stderr, _("Detected clock going backwards in time.\n"));
- fprintf(stderr, _("Time warp: %d ms\n"), diff);
+ fprintf(stderr, _("Time warp: %d ns\n"), diff);
exit(1);
}
--
2.50.1 (Apple Git-155)
[application/octet-stream] v3-0002-pg_test_timing-use-int64-for-largest-observed-tim.patch (2.4K, 3-v3-0002-pg_test_timing-use-int64-for-largest-observed-tim.patch)
download | inline diff:
From e193672cc7cd5736290af81a1ce8acd2f4237224 Mon Sep 17 00:00:00 2001
From: "Chao Li (Evan)" <[email protected]>
Date: Thu, 2 Apr 2026 10:29:06 +0800
Subject: [PATCH v3 2/2] pg_test_timing: use int64 for largest observed time
delta
pg_test_timing obtains timing deltas with INSTR_TIME_GET_NANOSEC(),
which returns a nanosecond value that should be stored in int64. Adjust
diff and largest_diff to use int64 accordingly.
Also fix the corresponding printf format specifiers so these values are
printed correctly.
Author: Chao Li <[email protected]>
Reviewed-by: Lukas Fittl <[email protected]>
Discussion: https://postgr.es/m/[email protected]
---
src/bin/pg_test_timing/pg_test_timing.c | 14 +++++++-------
1 file changed, 7 insertions(+), 7 deletions(-)
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index 944b25df1f2..ce4c54256e3 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -25,7 +25,7 @@ static long long int histogram[32];
static long long int direct_histogram[NUM_DIRECT];
/* separately record highest observed duration */
-static int32 largest_diff;
+static int64 largest_diff;
static long long int largest_diff_count;
@@ -262,8 +262,8 @@ test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timin
while (INSTR_TIME_GT(end_time, cur))
{
- int32 diff,
- bits;
+ int64 diff;
+ int32 bits;
instr_time diff_time;
prev = cur;
@@ -281,13 +281,13 @@ test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timin
if (unlikely(diff < 0))
{
fprintf(stderr, _("Detected clock going backwards in time.\n"));
- fprintf(stderr, _("Time warp: %d ns\n"), diff);
+ fprintf(stderr, _("Time warp: " INT64_FORMAT " ns\n"), diff);
exit(1);
}
/* What is the highest bit in the time diff? */
if (diff > 0)
- bits = pg_leftmost_one_pos32(diff) + 1;
+ bits = pg_leftmost_one_pos64(diff) + 1;
else
bits = 0;
@@ -409,8 +409,8 @@ output(uint64 loop_count)
double prct = (double) largest_diff_count * 100 / loop_count;
printf("...\n");
- printf("%*d %*.4f %*.4f %*lld\n",
- len1, largest_diff,
+ printf("%*lld %*.4f %*.4f %*lld\n",
+ len1, (long long) largest_diff,
len2, prct,
len3, 100.0,
len4, largest_diff_count);
--
2.50.1 (Apple Git-155)
view thread (11+ messages) latest in thread
reply
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: [email protected]
Cc: [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: pg_test_timing: fix unit typo and widen diff type
In-Reply-To: <[email protected]>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox