Message-ID: <68489e08.df0a0220.3c14af.fdc6@mx.google.com>
Sender: Michael Banck <mbanck@gmail.com>
Date: Tue, 10 Jun 2025 23:05:11 +0200
From: Michael Banck <mbanck@gmx.net>
To: Thomas Munro <thomas.munro@gmail.com>
Cc: Andres Freund <andres@anarazel.de>, Tom Lane <tgl@sss.pgh.pa.us>,
	Andrew Dunstan <andrew@dunslane.net>,
	Robert Haas <robertmhaas@gmail.com>,
	pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: Cleaning up historical portability baggage
References: <3322724.1659586159@sss.pgh.pa.us>
 <CA+hUKGJ5ej33AJL19sQph7Z8SFZ6+aUSKxFTS6pvk2Y8J9Tcwg@mail.gmail.com>
 <295419.1659918447@sss.pgh.pa.us>
 <CA+hUKGK=N8W2uFPdJr07Rs4dgRtbzKaYvCaPQasX3S8=aTO5PQ@mail.gmail.com>
 <747620.1660002360@sss.pgh.pa.us>
 <CA+hUKG+L_3brvh=8e0BW_VfX9h7MtwgN=nFHP5o7X2oZucY9dg@mail.gmail.com>
 <6846e0c3.df0a0220.39ef9b.c60e@mx.google.com>
 <n5hjl2cvnfr3oitguk5qmyep3ffb6ii5pfzcyezg4mjfb3ocqp@lt7iej77xiqw>
 <CA+hUKG+tqFVY7Fi=WBvZ6-UsATjcPNBDtphDm7YLjevm2kxSvw@mail.gmail.com>
 <68481005.df0a0220.23c1b8.78ca@mx.google.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="T4sUOijqQbZv57TR"
Content-Disposition: inline
In-Reply-To: <68481005.df0a0220.23c1b8.78ca@mx.google.com>
User-Agent: Mutt/1.10.1 (2018-07-13)
Archived-At: 
 <https://www.postgresql.org/message-id/68489e08.df0a0220.3c14af.fdc6%40mx.google.com>
Precedence: bulk


--T4sUOijqQbZv57TR
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

Hi,

On Tue, Jun 10, 2025 at 12:59:16PM +0200, Michael Banck wrote:
> On Tue, Jun 10, 2025 at 09:05:03AM +1200, Thomas Munro wrote:
> > https://savannah.gnu.org/task/?7050
> 
> 3. make check nowadays succeeds the subscription test that it failed in
> the log mentioned in the above task, but it still fails the stats test:

I take that back, the subscription test is flakey, but less so than the
stats test as it only has one of those stats_reset comparisons, compared
to several for stats. So I am seeing failures there only every few test
runs.

The reason those tests fail is that the Debian 12 era [1] GNU Mach I am
currently using has 10ms timer resolution, so some of those stats_reset
calls in quick succession do not lead to  different timestamps and the
checks fail.

There are several "SELECT pg_sleep(0.1);" calls in stats.sql already, so
I wonder whether a few more would be acceptable, or at least using
pg_sleep(0.01)? Using the attached, I no longer see regression failures,
even after running it for 10+ times.

The good news is maybe two-fold:

1. GNU Mach recently got better timer resolution and the version in
Debian unstable got that backported [2], so going forward this should
not be a problem anymore. I'll try upgrading my VM and see whether that
helps without the patch.

2. The fact that nobody else complained about those new(er) timestamp-
comparison additions appears to imply that there are no 100ms resolution
machines we support anymore. So did we consider switching those
pg_sleep(0.1) calls in stats.sql to pg_sleep(0.01) to save a bit of
time?


Michael

[1] As hurd-i386 is not a release architecture, there is no Debian 12
release for it. But the Debian GNU/Hurd porters made their own release
based on a snapshot of the hurd-i386 archive at time of the bookworm
release.
[2] https://salsa.debian.org/hurd-team/gnumach/-/blob/master/debian/patches/git-hpet?ref_type=heads

--T4sUOijqQbZv57TR
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="0001-Stabilize-stats_reset-based-tests-for-low-resolution.patch"

From a0b71da960ada0f5f8927920486e8a7096ac975b Mon Sep 17 00:00:00 2001
From: Michael Banck <mbanck@debian.org>
Date: Tue, 10 Jun 2025 22:55:44 +0200
Subject: [PATCH] Stabilize stats_reset-based tests for low-resolution timers.

On systems where the timestamp resolution is 10ms, two stats reset calls
in quick sucession and the comparison of their timestamps might not lead
to differences. Add 10ms pg_sleep() calls in order to ensure different
timestamps on those systems.

For the last_seq_scan timestamps tests we use 100ms pg_sleep() delays,
which we could reconsider adjusting to 10ms as well giving nobody else
complained about the stat reset tests without delay.
---
 src/test/regress/expected/stats.out        | 18 ++++++++++++++++++
 src/test/regress/expected/subscription.out |  6 ++++++
 src/test/regress/sql/stats.sql             |  3 +++
 src/test/regress/sql/subscription.sql      |  1 +
 4 files changed, 28 insertions(+)

diff --git a/src/test/regress/expected/stats.out b/src/test/regress/expected/stats.out
index 776f1ad0e53..803f4eac8ff 100644
--- a/src/test/regress/expected/stats.out
+++ b/src/test/regress/expected/stats.out
@@ -983,6 +983,12 @@ SELECT stats_reset > :'slru_commit_ts_reset_ts'::timestamptz FROM pg_stat_slru W
 
 SELECT stats_reset AS slru_commit_ts_reset_ts FROM pg_stat_slru WHERE name = 'commit_timestamp' \gset
 -- Test that multiple SLRUs are reset when no specific SLRU provided to reset function
+SELECT pg_sleep(0.01); -- assume a minimum timestamp granularity of 10ms
+ pg_sleep 
+----------
+ 
+(1 row)
+
 SELECT pg_stat_reset_slru();
  pg_stat_reset_slru 
 --------------------
@@ -1059,6 +1065,12 @@ SELECT stats_reset > :'recovery_prefetch_reset_ts'::timestamptz FROM pg_stat_rec
 
 -- Test that reset_shared with slru specified as the stats type works
 SELECT max(stats_reset) AS slru_reset_ts FROM pg_stat_slru \gset
+SELECT pg_sleep(0.01);
+ pg_sleep 
+----------
+ 
+(1 row)
+
 SELECT pg_stat_reset_shared('slru');
  pg_stat_reset_shared 
 ----------------------
@@ -1098,6 +1110,12 @@ SELECT pg_stat_reset();
 (1 row)
 
 SELECT stats_reset AS db_reset_ts FROM pg_stat_database WHERE datname = (SELECT current_database()) \gset
+SELECT pg_sleep(0.01);
+ pg_sleep 
+----------
+ 
+(1 row)
+
 SELECT pg_stat_reset();
  pg_stat_reset 
 ---------------
diff --git a/src/test/regress/expected/subscription.out b/src/test/regress/expected/subscription.out
index 1443e1d9292..a2baa599769 100644
--- a/src/test/regress/expected/subscription.out
+++ b/src/test/regress/expected/subscription.out
@@ -61,6 +61,12 @@ SELECT subname, stats_reset IS NULL stats_reset_is_null FROM pg_stat_subscriptio
 
 -- Reset the stats again and check if the new reset_stats is updated.
 SELECT stats_reset as prev_stats_reset FROM pg_stat_subscription_stats WHERE subname = 'regress_testsub' \gset
+SELECT pg_sleep(0.01);  -- assume a minimum timestamp granularity of 10ms
+ pg_sleep 
+----------
+ 
+(1 row)
+
 SELECT pg_stat_reset_subscription_stats(oid) FROM pg_subscription WHERE subname = 'regress_testsub';
  pg_stat_reset_subscription_stats 
 ----------------------------------
diff --git a/src/test/regress/sql/stats.sql b/src/test/regress/sql/stats.sql
index 232ab8db8fa..b78dc0c670d 100644
--- a/src/test/regress/sql/stats.sql
+++ b/src/test/regress/sql/stats.sql
@@ -467,6 +467,7 @@ SELECT stats_reset > :'slru_commit_ts_reset_ts'::timestamptz FROM pg_stat_slru W
 SELECT stats_reset AS slru_commit_ts_reset_ts FROM pg_stat_slru WHERE name = 'commit_timestamp' \gset
 
 -- Test that multiple SLRUs are reset when no specific SLRU provided to reset function
+SELECT pg_sleep(0.01); -- assume a minimum timestamp granularity of 10ms
 SELECT pg_stat_reset_slru();
 SELECT stats_reset > :'slru_commit_ts_reset_ts'::timestamptz FROM pg_stat_slru WHERE name = 'commit_timestamp';
 SELECT stats_reset > :'slru_notify_reset_ts'::timestamptz FROM pg_stat_slru WHERE name = 'notify';
@@ -493,6 +494,7 @@ SELECT stats_reset > :'recovery_prefetch_reset_ts'::timestamptz FROM pg_stat_rec
 
 -- Test that reset_shared with slru specified as the stats type works
 SELECT max(stats_reset) AS slru_reset_ts FROM pg_stat_slru \gset
+SELECT pg_sleep(0.01);
 SELECT pg_stat_reset_shared('slru');
 SELECT max(stats_reset) > :'slru_reset_ts'::timestamptz FROM pg_stat_slru;
 
@@ -509,6 +511,7 @@ SELECT pg_stat_reset_shared('unknown');
 -- Since pg_stat_database stats_reset starts out as NULL, reset it once first so we have something to compare it to
 SELECT pg_stat_reset();
 SELECT stats_reset AS db_reset_ts FROM pg_stat_database WHERE datname = (SELECT current_database()) \gset
+SELECT pg_sleep(0.01);
 SELECT pg_stat_reset();
 SELECT stats_reset > :'db_reset_ts'::timestamptz FROM pg_stat_database WHERE datname = (SELECT current_database());
 
diff --git a/src/test/regress/sql/subscription.sql b/src/test/regress/sql/subscription.sql
index 007c9e70374..d0ec8d18fa1 100644
--- a/src/test/regress/sql/subscription.sql
+++ b/src/test/regress/sql/subscription.sql
@@ -39,6 +39,7 @@ SELECT subname, stats_reset IS NULL stats_reset_is_null FROM pg_stat_subscriptio
 
 -- Reset the stats again and check if the new reset_stats is updated.
 SELECT stats_reset as prev_stats_reset FROM pg_stat_subscription_stats WHERE subname = 'regress_testsub' \gset
+SELECT pg_sleep(0.01);  -- assume a minimum timestamp granularity of 10ms
 SELECT pg_stat_reset_subscription_stats(oid) FROM pg_subscription WHERE subname = 'regress_testsub';
 SELECT :'prev_stats_reset' < stats_reset FROM pg_stat_subscription_stats WHERE subname = 'regress_testsub';
 
-- 
2.39.5


--T4sUOijqQbZv57TR--