public inbox for [email protected]  
help / color / mirror / Atom feed
From: Chao Li <[email protected]>
To: Fujii Masao <[email protected]>
Cc: wang.xiao.peng <[email protected]>
Cc: [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: Thu, 23 Apr 2026 10:02:31 +0800
Message-ID: <[email protected]> (raw)
In-Reply-To: <CAHGQGwHFHghHRn1427m_ZH_D9t0gytKRa96Uid-pJ4VyZCvyOw@mail.gmail.com>
References: <[email protected]>
	<CAP53PkwEZ+UMmwA8cbUSUdE6phXi+xWmn5t-YAnvKf0qoBnOvg@mail.gmail.com>
	<[email protected]>
	<[email protected]>
	<[email protected]>
	<CAHGQGwEM=s5vXPpXoismwRMNCnAmwwMJPnQEQYbPFTJGouV0rQ@mail.gmail.com>
	<[email protected]>
	<CAHGQGwHFHghHRn1427m_ZH_D9t0gytKRa96Uid-pJ4VyZCvyOw@mail.gmail.com>



> On Apr 23, 2026, at 00:11, Fujii Masao <[email protected]> wrote:
> 
> On Wed, Apr 22, 2026 at 5:58 PM Chao Li <[email protected]> wrote:
>> PFA v4:
>> 
>> * 0001 unchanged from v3.
>> * 0002 changed size of histogram[] 64.
> 
> Thanks for updating the patch!
> 
> Since patch 0001 is a bug fix, it should be backpatched to the supported stable
> branches. However, in v19 the unit should be changed like s/ms/ns, while in v18
> and earlier s/ms/us, since those older branches report the diff in microseconds.
> Right?

I just checked old branches. Looks like 0001 can be back-patched down to v10. Yes, pre-19, all branches use microsecond, so the back-patch should change “ms” to “us”.

I have helped create back-patch diff files as attached:

* nocfbot.v10-v13.pg_test_timing-backpatch.diff for v10-v13
* nocfbot.v14-v15.pg_test_timing-backpatch.diff for v14-v15
* nocfbot.v16-v18.pg_test_timing-backpatch.diff for v16-v18

For v16 to v18, we can make a tiny improvement by replacing “1e9” with a constant macro NS_PER_S. This change has been included in the diff.

I have built and tested on all branches.

> 
> Patch 0002 looks more like an improvement than a bug fix, so we should probably
> wait for the next CommitFest before committing it. Thoughts?
> 

I see 0002 a bit differently. In v19, the unit changed from microseconds to nanoseconds, which introduced a potential overflow: nanoseconds require int64, but the local variable remained int32. So I think this is actually a v19-only bug.

PFA v5: 0001 replaced “1e9” with NS_PER_S; 0002 unchanged.

Best regards,
--
Chao Li (Evan)
HighGo Software Co., Ltd.
https://www.highgo.com/






Attachments:

  [application/octet-stream] nocfbot.v10-v13.pg_test_timing-backpatch.diff (488B, 2-nocfbot.v10-v13.pg_test_timing-backpatch.diff)
  download | inline diff:
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index e14802372bd..79ef32353dc 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -138,7 +138,7 @@ test_timing(int32 duration)
 		if (diff < 0)
 		{
 			fprintf(stderr, _("Detected clock going backwards in time.\n"));
-			fprintf(stderr, _("Time warp: %d ms\n"), diff);
+			fprintf(stderr, _("Time warp: %d us\n"), diff);
 			exit(1);
 		}
 


  [application/octet-stream] nocfbot.v14-v15.pg_test_timing-backpatch.diff (495B, 3-nocfbot.v14-v15.pg_test_timing-backpatch.diff)
  download | inline diff:
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index c29d6f87629..0ccf55761ce 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -149,7 +149,7 @@ test_timing(unsigned int duration)
 		if (diff < 0)
 		{
 			fprintf(stderr, _("Detected clock going backwards in time.\n"));
-			fprintf(stderr, _("Time warp: %d ms\n"), diff);
+			fprintf(stderr, _("Time warp: %d us\n"), diff);
 			exit(1);
 		}
 


  [application/octet-stream] nocfbot.v16-v18.pg_test_timing-backpatch.diff (806B, 4-nocfbot.v16-v18.pg_test_timing-backpatch.diff)
  download | inline diff:
diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index ce7aad4b25a..3c7672f592d 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -149,7 +149,7 @@ test_timing(unsigned int duration)
 		if (diff < 0)
 		{
 			fprintf(stderr, _("Detected clock going backwards in time.\n"));
-			fprintf(stderr, _("Time warp: %d ms\n"), diff);
+			fprintf(stderr, _("Time warp: %d us\n"), diff);
 			exit(1);
 		}
 
@@ -173,7 +173,7 @@ test_timing(unsigned int duration)
 	INSTR_TIME_SUBTRACT(end_time, start_time);
 
 	printf(_("Per loop time including overhead: %0.2f ns\n"),
-		   INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
+		   INSTR_TIME_GET_DOUBLE(end_time) * NS_PER_S / loop_count);
 
 	return loop_count;
 }


  [application/octet-stream] v5-0001-pg_test_timing-fix-unit-in-backward-clock-warning.patch (1.7K, 5-v5-0001-pg_test_timing-fix-unit-in-backward-clock-warning.patch)
  download | inline diff:
From ee388e247cc7d2473b12ca370b06cc9bbf0037fd Mon Sep 17 00:00:00 2001
From: "Chao Li (Evan)" <[email protected]>
Date: Thu, 2 Apr 2026 10:21:40 +0800
Subject: [PATCH v5 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]>
Reviewed-by: Fujii Masao <[email protected]>
Discussion: https://postgr.es/m/[email protected]
---
 src/bin/pg_test_timing/pg_test_timing.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index 2afb0e6a410..5eb20e091b1 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);
 		}
 
@@ -316,7 +316,7 @@ test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timin
 	INSTR_TIME_SUBTRACT(end_time, start_time);
 
 	printf(_("Average loop time including overhead: %0.2f ns\n"),
-		   INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
+		   INSTR_TIME_GET_DOUBLE(end_time) * NS_PER_S / loop_count);
 
 	return loop_count;
 }
-- 
2.50.1 (Apple Git-155)



  [application/octet-stream] v5-0002-pg_test_timing-use-int64-for-largest-observed-tim.patch (3.6K, 6-v5-0002-pg_test_timing-use-int64-for-largest-observed-tim.patch)
  download | inline diff:
From 3eea80de37049bd453cf5724951c18505d557a99 Mon Sep 17 00:00:00 2001
From: "Chao Li (Evan)" <[email protected]>
Date: Thu, 2 Apr 2026 10:29:06 +0800
Subject: [PATCH v5 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]>
Reviewed-by: Fujii Masao <[email protected]>
Discussion: https://postgr.es/m/[email protected]
---
 src/bin/pg_test_timing/pg_test_timing.c | 28 ++++++++++++++-----------
 1 file changed, 16 insertions(+), 12 deletions(-)

diff --git a/src/bin/pg_test_timing/pg_test_timing.c b/src/bin/pg_test_timing/pg_test_timing.c
index 5eb20e091b1..340b529e972 100644
--- a/src/bin/pg_test_timing/pg_test_timing.c
+++ b/src/bin/pg_test_timing/pg_test_timing.c
@@ -18,14 +18,14 @@ static unsigned int test_duration = 3;
 static double max_rprct = 99.99;
 
 /* record duration in powers of 2 nanoseconds */
-static long long int histogram[32];
+static long long int histogram[64];
 
 /* record counts of first 10K durations directly */
 #define NUM_DIRECT 10000
 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,17 @@ 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;
+			/* histogram should be define large enough */
+			Assert(bits < lengthof(histogram));
+		}
 		else
 			bits = 0;
 
@@ -324,7 +328,7 @@ test_timing(unsigned int duration, TimingClockSourceType source, bool fast_timin
 static void
 output(uint64 loop_count)
 {
-	int			max_bit = 31;
+	int			max_bit = lengthof(histogram) - 1;
 	const char *header1 = _("<= ns");
 	const char *header1b = _("ns");
 	const char *header2 = /* xgettext:no-c-format */ _("% of total");
@@ -342,7 +346,7 @@ output(uint64 loop_count)
 		max_bit--;
 
 	/* set minimum column widths */
-	len1 = Max(8, len1);
+	len1 = Max(19, len1);
 	len2 = Max(10, len2);
 	len3 = Max(10, len3);
 	len4 = Max(10, len4);
@@ -360,8 +364,8 @@ output(uint64 loop_count)
 		double		prct = (double) histogram[i] * 100 / loop_count;
 
 		rprct += prct;
-		printf("%*ld   %*.4f %*.4f %*lld\n",
-			   len1, (1L << i) - 1,
+		printf("%*llu   %*.4f %*.4f %*lld\n",
+			   len1, (1ULL << i) - 1,
 			   len2, prct,
 			   len3, rprct,
 			   len4, histogram[i]);
@@ -409,8 +413,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], [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