On Mon, Apr 20, 2020 at 8:02 PM Dilip Kumar <dilipbal...@gmail.com> wrote:
> On Mon, Apr 20, 2020 at 12:29 PM Thomas Munro <thomas.mu...@gmail.com> wrote:
> > I mean I want to verify that VACUUM or heap prune actually removed a
> > tuple that was visible to an old snapshot.  An idea I just had: maybe
> > sto_using_select.spec should check the visibility map (somehow).  For
> > example, the sto_using_select.spec (the version in the patch I just
> > posted) just checks that after time 00:11, the old snapshot gets a
> > snapshot-too-old error.  Perhaps we could add a VACUUM before that,
> > and then check that the page has become all visible, meaning that the
> > dead tuple our snapshot could see has now been removed.
>
> Okay, got your point.  Can we try to implement some test functions
> that can just call visibilitymap_get_status function internally?  I
> agree that we will have to pass the correct block number but that we
> can find using TID.   Or for testing, we can create a very small
> relation that just has 1 block?

I think it's enough to check SELECT EVERY(all_visible) FROM
pg_visibility_map('sto1'::regclass).  I realised that
src/test/module/snapshot_too_old is allowed to install
contrib/pg_visibility with EXTRA_INSTALL, so here's a new version to
try that idea.  It extends sto_using_select.spec to VACUUM and check
the vis map at key times.  That allows us to check that early pruning
really happens once the snapshot becomes too old.  There are other
ways you could check that but this seems quite "light touch" compared
to something based on page inspection.

I also changed src/test/module/snapshot_too_old/t/001_truncate.pl back
to using Robert's contrib/old_snapshot extension to know the size of
the time/xid map, allowing an introspection function to be dropped
from test_sto.c.

As before, these two apply on top of Robert's patches (or at least his
0001 and 0002).
From 28f81e93e8058d64c80d2b2b605a57f48ceebc0b Mon Sep 17 00:00:00 2001
From: Thomas Munro <thomas.mu...@gmail.com>
Date: Mon, 20 Apr 2020 16:23:02 +1200
Subject: [PATCH v4 4/5] Rewrite the "snapshot_too_old" tests.

Previously the snapshot too old feature used a special test value for
old_snapshot_threshold.  Instead, use a new approach based on explicitly
advancing the "current" timestamp used in snapshot-too-old book keeping,
so that we can control the timeline precisely without having to resort
to sleeping or special test branches in the code.

Also check that early pruning actually happens, by vacuuming and
inspecting the visibility map at key points in the test schedule.
---
 src/backend/utils/time/snapmgr.c              |  24 ---
 src/test/modules/snapshot_too_old/Makefile    |  23 +--
 .../expected/sto_using_cursor.out             |  75 ++++-----
 .../expected/sto_using_hash_index.out         |  26 ++-
 .../expected/sto_using_select.out             | 157 +++++++++++++++---
 .../specs/sto_using_cursor.spec               |  30 ++--
 .../specs/sto_using_hash_index.spec           |  19 ++-
 .../specs/sto_using_select.spec               |  50 ++++--
 src/test/modules/snapshot_too_old/sto.conf    |   2 +-
 .../snapshot_too_old/test_sto--1.0.sql        |  14 ++
 src/test/modules/snapshot_too_old/test_sto.c  |  74 +++++++++
 .../modules/snapshot_too_old/test_sto.control |   5 +
 12 files changed, 366 insertions(+), 133 deletions(-)
 create mode 100644 src/test/modules/snapshot_too_old/test_sto--1.0.sql
 create mode 100644 src/test/modules/snapshot_too_old/test_sto.c
 create mode 100644 src/test/modules/snapshot_too_old/test_sto.control

diff --git a/src/backend/utils/time/snapmgr.c b/src/backend/utils/time/snapmgr.c
index 72b2c61a07..19e6c52b80 100644
--- a/src/backend/utils/time/snapmgr.c
+++ b/src/backend/utils/time/snapmgr.c
@@ -1739,26 +1739,6 @@ TransactionIdLimitedForOldSnapshots(TransactionId recentXmin,
 		update_ts = oldSnapshotControl->next_map_update;
 		SpinLockRelease(&oldSnapshotControl->mutex_latest_xmin);
 
-		/*
-		 * Zero threshold always overrides to latest xmin, if valid.  Without
-		 * some heuristic it will find its own snapshot too old on, for
-		 * example, a simple UPDATE -- which would make it useless for most
-		 * testing, but there is no principled way to ensure that it doesn't
-		 * fail in this way.  Use a five-second delay to try to get useful
-		 * testing behavior, but this may need adjustment.
-		 */
-		if (old_snapshot_threshold == 0)
-		{
-			if (TransactionIdPrecedes(latest_xmin, MyPgXact->xmin)
-				&& TransactionIdFollows(latest_xmin, xlimit))
-				xlimit = latest_xmin;
-
-			ts -= 5 * USECS_PER_SEC;
-			SetOldSnapshotThresholdTimestamp(ts, xlimit);
-
-			return xlimit;
-		}
-
 		ts = AlignTimestampToMinuteBoundary(ts)
 			- (old_snapshot_threshold * USECS_PER_MINUTE);
 
@@ -1860,10 +1840,6 @@ MaintainOldSnapshotTimeMapping(TimestampTz whenTaken, TransactionId xmin)
 	if (!map_update_required)
 		return;
 
-	/* No further tracking needed for 0 (used for testing). */
-	if (old_snapshot_threshold == 0)
-		return;
-
 	/*
 	 * We don't want to do something stupid with unusual values, but we don't
 	 * want to litter the log with warnings or break otherwise normal
diff --git a/src/test/modules/snapshot_too_old/Makefile b/src/test/modules/snapshot_too_old/Makefile
index dfb4537f63..81836e9953 100644
--- a/src/test/modules/snapshot_too_old/Makefile
+++ b/src/test/modules/snapshot_too_old/Makefile
@@ -1,14 +1,22 @@
 # src/test/modules/snapshot_too_old/Makefile
 
-# Note: because we don't tell the Makefile there are any regression tests,
-# we have to clean those result files explicitly
-EXTRA_CLEAN = $(pg_regress_clean_files)
+MODULE_big = test_sto
+OBJS = \
+	$(WIN32RES) \
+	test_sto.o
+
+EXTENSION = test_sto
+DATA = test_sto--1.0.sql
+PGDESCFILE = "test_sto -- internal testing for snapshot too old errors"
+
+EXTRA_INSTALL = contrib/pg_visibility
 
 ISOLATION = sto_using_cursor sto_using_select sto_using_hash_index
 ISOLATION_OPTS = --temp-config $(top_srcdir)/src/test/modules/snapshot_too_old/sto.conf
 
-# Disabled because these tests require "old_snapshot_threshold" >= 0, which
-# typical installcheck users do not have (e.g. buildfarm clients).
+# Disabled because these tests require "old_snapshot_threshold" = 10, which
+# typical installcheck users do not have (e.g. buildfarm clients) and also
+# because it'd be dangerous on a production system.
 NO_INSTALLCHECK = 1
 
 ifdef USE_PGXS
@@ -21,8 +29,3 @@ top_builddir = ../../../..
 include $(top_builddir)/src/Makefile.global
 include $(top_srcdir)/contrib/contrib-global.mk
 endif
-
-# But it can nonetheless be very helpful to run tests on preexisting
-# installation, allow to do so, but only if requested explicitly.
-installcheck-force:
-	$(pg_isolation_regress_installcheck) $(ISOLATION)
diff --git a/src/test/modules/snapshot_too_old/expected/sto_using_cursor.out b/src/test/modules/snapshot_too_old/expected/sto_using_cursor.out
index 8cc29ec82f..b007e2dc17 100644
--- a/src/test/modules/snapshot_too_old/expected/sto_using_cursor.out
+++ b/src/test/modules/snapshot_too_old/expected/sto_using_cursor.out
@@ -1,73 +1,60 @@
-Parsed test spec with 2 sessions
+Parsed test spec with 3 sessions
 
-starting permutation: s1decl s1f1 s1sleep s1f2 s2u
+starting permutation: t00 s1decl s1f1 t10 s2u s1f2 t20 s1f3
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
 step s1decl: DECLARE cursor1 CURSOR FOR SELECT c FROM sto1;
 step s1f1: FETCH FIRST FROM cursor1;
 c              
 
 1              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step t10: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:10:00Z');
+test_sto_clobber_snapshot_timestamp
 
-0                             
+               
+step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
 step s1f2: FETCH FIRST FROM cursor1;
 c              
 
 1              
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
+step t20: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:20:00Z');
+test_sto_clobber_snapshot_timestamp
 
-starting permutation: s1decl s1f1 s1sleep s2u s1f2
-step s1decl: DECLARE cursor1 CURSOR FOR SELECT c FROM sto1;
-step s1f1: FETCH FIRST FROM cursor1;
-c              
+               
+step s1f3: FETCH FIRST FROM cursor1;
+ERROR:  snapshot too old
+test_sto_reset_all_state
 
-1              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+               
 
-0                             
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1f2: FETCH FIRST FROM cursor1;
-ERROR:  snapshot too old
+starting permutation: t00 s1decl s1f1 t10 s1f2 t20 s1f3
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
 
-starting permutation: s1decl s1f1 s2u s1sleep s1f2
+               
 step s1decl: DECLARE cursor1 CURSOR FOR SELECT c FROM sto1;
 step s1f1: FETCH FIRST FROM cursor1;
 c              
 
 1              
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step t10: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:10:00Z');
+test_sto_clobber_snapshot_timestamp
 
-0                             
+               
 step s1f2: FETCH FIRST FROM cursor1;
-ERROR:  snapshot too old
-
-starting permutation: s1decl s2u s1f1 s1sleep s1f2
-step s1decl: DECLARE cursor1 CURSOR FOR SELECT c FROM sto1;
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1f1: FETCH FIRST FROM cursor1;
 c              
 
 1              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
-
-0                             
-step s1f2: FETCH FIRST FROM cursor1;
-ERROR:  snapshot too old
+step t20: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:20:00Z');
+test_sto_clobber_snapshot_timestamp
 
-starting permutation: s2u s1decl s1f1 s1sleep s1f2
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1decl: DECLARE cursor1 CURSOR FOR SELECT c FROM sto1;
-step s1f1: FETCH FIRST FROM cursor1;
+               
+step s1f3: FETCH FIRST FROM cursor1;
 c              
 
-2              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+1              
+test_sto_reset_all_state
 
-0                             
-step s1f2: FETCH FIRST FROM cursor1;
-ERROR:  snapshot too old
+               
diff --git a/src/test/modules/snapshot_too_old/expected/sto_using_hash_index.out b/src/test/modules/snapshot_too_old/expected/sto_using_hash_index.out
index bf94054790..091c212adc 100644
--- a/src/test/modules/snapshot_too_old/expected/sto_using_hash_index.out
+++ b/src/test/modules/snapshot_too_old/expected/sto_using_hash_index.out
@@ -1,15 +1,31 @@
-Parsed test spec with 2 sessions
+Parsed test spec with 3 sessions
 
-starting permutation: noseq s1f1 s2sleep s2u s1f2
+starting permutation: t00 noseq s1f1 t10 s2u s2v1 s1f2 t22 s2v2 s1f3
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
 step noseq: SET enable_seqscan = false;
 step s1f1: SELECT c FROM sto1 where c = 1000;
 c              
 
 1000           
-step s2sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step t10: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:10:00Z');
+test_sto_clobber_snapshot_timestamp
 
-0                             
+               
 step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1000;
+step s2v1: VACUUM sto1;
 step s1f2: SELECT c FROM sto1 where c = 1001;
+c              
+
+step t22: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:22:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2v2: VACUUM sto1;
+step s1f3: SELECT c FROM sto1 where c = 1001;
 ERROR:  snapshot too old
+test_sto_reset_all_state
+
+               
diff --git a/src/test/modules/snapshot_too_old/expected/sto_using_select.out b/src/test/modules/snapshot_too_old/expected/sto_using_select.out
index eb15bc23bf..201c106754 100644
--- a/src/test/modules/snapshot_too_old/expected/sto_using_select.out
+++ b/src/test/modules/snapshot_too_old/expected/sto_using_select.out
@@ -1,55 +1,164 @@
-Parsed test spec with 2 sessions
+Parsed test spec with 3 sessions
 
-starting permutation: s1f1 s1sleep s1f2 s2u
+starting permutation: t00 s2vis1 s1f1 t01 s2u s2vis2 s1f2 t11 s2vac1 s2vis3 s1f3 t12 s1f4 s2vac2 s2vis4
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vis1: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
 step s1f1: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 c              
 
 1              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step t01: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:01:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
+step s2vis2: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
 
-0                             
+f              
 step s1f2: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 c              
 
 1              
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
+step t11: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:11:00Z');
+test_sto_clobber_snapshot_timestamp
 
-starting permutation: s1f1 s1sleep s2u s1f2
-step s1f1: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+               
+step s2vac1: VACUUM sto1;
+step s2vis3: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+f              
+step s1f3: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 c              
 
 1              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step t12: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:12:00Z');
+test_sto_clobber_snapshot_timestamp
 
-0                             
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1f2: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+               
+step s1f4: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 ERROR:  snapshot too old
+step s2vac2: VACUUM sto1;
+step s2vis4: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
+test_sto_reset_all_state
+
+               
+
+starting permutation: t00 s2vis1 s1f1 t01 s2u s2vis2 s1f2 t11 s2vac1 s2vis3 s1f3 t12 s2vac2 s2vis4 s1f4
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
 
-starting permutation: s1f1 s2u s1sleep s1f2
+               
+step s2vis1: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
 step s1f1: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 c              
 
 1              
+step t01: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:01:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
 step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+step s2vis2: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
 
-0                             
+f              
 step s1f2: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+c              
+
+1              
+step t11: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:11:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vac1: VACUUM sto1;
+step s2vis3: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+f              
+step s1f3: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+c              
+
+1              
+step t12: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:12:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vac2: VACUUM sto1;
+step s2vis4: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
+step s1f4: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 ERROR:  snapshot too old
+test_sto_reset_all_state
 
-starting permutation: s2u s1f1 s1sleep s1f2
-step s2u: UPDATE sto1 SET c = 1001 WHERE c = 1;
+               
+
+starting permutation: t00 s2vis1 s1f1 t01 s2vis2 s1f2 t11 s2vac1 s2vis3 s1f3 t12 s2vac2 s2vis4 s1f4
+step t00: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vis1: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
 step s1f1: SELECT c FROM sto1 ORDER BY c LIMIT 1;
 c              
 
-2              
-step s1sleep: SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold';
-setting        pg_sleep       
+1              
+step t01: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:01:00Z');
+test_sto_clobber_snapshot_timestamp
 
-0                             
+               
+step s2vis2: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
 step s1f2: SELECT c FROM sto1 ORDER BY c LIMIT 1;
-ERROR:  snapshot too old
+c              
+
+1              
+step t11: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:11:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vac1: VACUUM sto1;
+step s2vis3: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
+step s1f3: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+c              
+
+1              
+step t12: SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:12:00Z');
+test_sto_clobber_snapshot_timestamp
+
+               
+step s2vac2: VACUUM sto1;
+step s2vis4: SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass);
+every          
+
+t              
+step s1f4: SELECT c FROM sto1 ORDER BY c LIMIT 1;
+c              
+
+1              
+test_sto_reset_all_state
+
+               
diff --git a/src/test/modules/snapshot_too_old/specs/sto_using_cursor.spec b/src/test/modules/snapshot_too_old/specs/sto_using_cursor.spec
index eac18ca5b9..3be084b8fe 100644
--- a/src/test/modules/snapshot_too_old/specs/sto_using_cursor.spec
+++ b/src/test/modules/snapshot_too_old/specs/sto_using_cursor.spec
@@ -1,19 +1,14 @@
 # This test provokes a "snapshot too old" error using a cursor.
 #
-# The sleep is needed because with a threshold of zero a statement could error
-# on changes it made.  With more normal settings no external delay is needed,
-# but we don't want these tests to run long enough to see that, since
-# granularity is in minutes.
-#
-# Since results depend on the value of old_snapshot_threshold, sneak that into
-# the line generated by the sleep, so that a surprising values isn't so hard
-# to identify.
+# Expects old_snapshot_threshold = 10.  Not suitable for installcheck since it
+# messes with internal snapmgr.c state.
 
 setup
 {
+    CREATE EXTENSION IF NOT EXISTS test_sto;
+    SELECT test_sto_reset_all_state();
     CREATE TABLE sto1 (c int NOT NULL);
     INSERT INTO sto1 SELECT generate_series(1, 1000);
-    CREATE TABLE sto2 (c int NOT NULL);
 }
 setup
 {
@@ -22,16 +17,29 @@ setup
 
 teardown
 {
-    DROP TABLE sto1, sto2;
+    DROP TABLE sto1;
+    SELECT test_sto_reset_all_state();
 }
 
 session "s1"
 setup			{ BEGIN ISOLATION LEVEL REPEATABLE READ; }
 step "s1decl"	{ DECLARE cursor1 CURSOR FOR SELECT c FROM sto1; }
 step "s1f1"		{ FETCH FIRST FROM cursor1; }
-step "s1sleep"	{ SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold'; }
 step "s1f2"		{ FETCH FIRST FROM cursor1; }
+step "s1f3"		{ FETCH FIRST FROM cursor1; }
 teardown		{ COMMIT; }
 
 session "s2"
 step "s2u"		{ UPDATE sto1 SET c = 1001 WHERE c = 1; }
+
+session "time"
+step "t00"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z'); }
+step "t10"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:10:00Z'); }
+step "t20"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:20:00Z'); }
+
+# if there's an update, we get a snapshot too old error at time 00:20 (not before,
+# because we need page pruning to see the xmin level change from 10 minutes earlier)
+permutation "t00" "s1decl" "s1f1" "t10" "s2u" "s1f2" "t20" "s1f3"
+
+# if there's no update, no snapshot too old error at time 00:20
+permutation "t00" "s1decl" "s1f1" "t10"       "s1f2" "t20" "s1f3"
diff --git a/src/test/modules/snapshot_too_old/specs/sto_using_hash_index.spec b/src/test/modules/snapshot_too_old/specs/sto_using_hash_index.spec
index 33d91ff852..f90bca3b7a 100644
--- a/src/test/modules/snapshot_too_old/specs/sto_using_hash_index.spec
+++ b/src/test/modules/snapshot_too_old/specs/sto_using_hash_index.spec
@@ -1,8 +1,12 @@
 # This test is like sto_using_select, except that we test access via a
-# hash index.
+# hash index.  Explicit vacuuming is required in this version because
+# there is are no incidental calls to heap_page_prune_opt() that can
+# call SetOldSnapshotThresholdTimestamp().
 
 setup
 {
+	CREATE EXTENSION IF NOT EXISTS test_sto;
+	SELECT test_sto_reset_all_state();
     CREATE TABLE sto1 (c int NOT NULL);
     INSERT INTO sto1 SELECT generate_series(1, 1000);
     CREATE INDEX idx_sto1 ON sto1 USING HASH (c);
@@ -15,6 +19,7 @@ setup
 teardown
 {
     DROP TABLE sto1;
+	SELECT test_sto_reset_all_state();
 }
 
 session "s1"
@@ -22,10 +27,18 @@ setup			{ BEGIN ISOLATION LEVEL REPEATABLE READ; }
 step "noseq"	{ SET enable_seqscan = false; }
 step "s1f1"		{ SELECT c FROM sto1 where c = 1000; }
 step "s1f2"		{ SELECT c FROM sto1 where c = 1001; }
+step "s1f3"		{ SELECT c FROM sto1 where c = 1001; }
 teardown		{ ROLLBACK; }
 
 session "s2"
-step "s2sleep"	{ SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold'; }
 step "s2u"		{ UPDATE sto1 SET c = 1001 WHERE c = 1000; }
+step "s2v1"		{ VACUUM sto1; }
+step "s2v2"		{ VACUUM sto1; }
 
-permutation "noseq" "s1f1" "s2sleep" "s2u" "s1f2"
+session "time"
+step "t00"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z'); }
+step "t10"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:10:00Z'); }
+step "t22"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:22:00Z'); }
+
+# snapshot too old at t22
+permutation "t00" "noseq" "s1f1" "t10" "s2u" "s2v1" "s1f2" "t22" "s2v2" "s1f3"
diff --git a/src/test/modules/snapshot_too_old/specs/sto_using_select.spec b/src/test/modules/snapshot_too_old/specs/sto_using_select.spec
index d7c34f3d89..cd7a97b742 100644
--- a/src/test/modules/snapshot_too_old/specs/sto_using_select.spec
+++ b/src/test/modules/snapshot_too_old/specs/sto_using_select.spec
@@ -1,19 +1,15 @@
 # This test provokes a "snapshot too old" error using SELECT statements.
 #
-# The sleep is needed because with a threshold of zero a statement could error
-# on changes it made.  With more normal settings no external delay is needed,
-# but we don't want these tests to run long enough to see that, since
-# granularity is in minutes.
-#
-# Since results depend on the value of old_snapshot_threshold, sneak that into
-# the line generated by the sleep, so that a surprising values isn't so hard
-# to identify.
+# Expects old_snapshot_threshold = 10.  Not suitable for installcheck since it
+# messes with internal snapmgr.c state.
 
 setup
 {
+	CREATE EXTENSION IF NOT EXISTS test_sto;
+	CREATE EXTENSION IF NOT EXISTS pg_visibility;
+	SELECT test_sto_reset_all_state();
     CREATE TABLE sto1 (c int NOT NULL);
     INSERT INTO sto1 SELECT generate_series(1, 1000);
-    CREATE TABLE sto2 (c int NOT NULL);
 }
 setup
 {
@@ -22,15 +18,47 @@ setup
 
 teardown
 {
-    DROP TABLE sto1, sto2;
+	DROP TABLE sto1;
+    SELECT test_sto_reset_all_state();
 }
 
 session "s1"
 setup			{ BEGIN ISOLATION LEVEL REPEATABLE READ; }
 step "s1f1"		{ SELECT c FROM sto1 ORDER BY c LIMIT 1; }
-step "s1sleep"	{ SELECT setting, pg_sleep(6) FROM pg_settings WHERE name = 'old_snapshot_threshold'; }
 step "s1f2"		{ SELECT c FROM sto1 ORDER BY c LIMIT 1; }
+step "s1f3"		{ SELECT c FROM sto1 ORDER BY c LIMIT 1; }
+step "s1f4"		{ SELECT c FROM sto1 ORDER BY c LIMIT 1; }
 teardown		{ COMMIT; }
 
 session "s2"
+step "s2vis1"	{ SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass); }
 step "s2u"		{ UPDATE sto1 SET c = 1001 WHERE c = 1; }
+step "s2vis2"	{ SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass); }
+step "s2vac1"	{ VACUUM sto1; }
+step "s2vis3"	{ SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass); }
+step "s2vac2"	{ VACUUM sto1; }
+step "s2vis4"	{ SELECT EVERY(all_visible) FROM pg_visibility_map('sto1'::regclass); }
+
+session "time"
+step "t00"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z'); }
+step "t01"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:01:00Z'); }
+step "t11"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:11:00Z'); }
+step "t12"		{ SELECT test_sto_clobber_snapshot_timestamp('3000-01-01 00:12:00Z'); }
+
+# If there's an update, we get a snapshot too old error at time 00:12, and
+# VACUUM is allowed to remove the tuple our snapshot could see, which we know
+# because we see that the relation becomes all visible.  The earlier VACUUMs
+# were unable to remove the tuple we could see, which is is obvious because we
+# can see the row with value 1, and from the relation not being all visible
+# after the VACUUM.
+permutation "t00" "s2vis1" "s1f1" "t01" "s2u" "s2vis2" "s1f2" "t11" "s2vac1" "s2vis3" "s1f3" "t12" "s1f4" "s2vac2" "s2vis4"
+
+# Almost the same schedule, but this time we'll put s2vac2 and s2vis4 before
+# s1f4 just to demonstrate that the early pruning is allowed before the error
+# aborts s1's transaction.
+permutation "t00" "s2vis1" "s1f1" "t01" "s2u" "s2vis2" "s1f2" "t11" "s2vac1" "s2vis3" "s1f3" "t12" "s2vac2" "s2vis4" "s1f4"
+
+# If we run the same schedule as above but without the update, we get no
+# snapshot too old error (even though our snapshot is older than the
+# threshold), and the relation remains all visible.
+permutation "t00" "s2vis1" "s1f1" "t01"       "s2vis2" "s1f2" "t11" "s2vac1" "s2vis3" "s1f3" "t12" "s2vac2" "s2vis4" "s1f4"
diff --git a/src/test/modules/snapshot_too_old/sto.conf b/src/test/modules/snapshot_too_old/sto.conf
index 7eeaeeb0dc..5ed46b3560 100644
--- a/src/test/modules/snapshot_too_old/sto.conf
+++ b/src/test/modules/snapshot_too_old/sto.conf
@@ -1,2 +1,2 @@
 autovacuum = off
-old_snapshot_threshold = 0
+old_snapshot_threshold = 10
diff --git a/src/test/modules/snapshot_too_old/test_sto--1.0.sql b/src/test/modules/snapshot_too_old/test_sto--1.0.sql
new file mode 100644
index 0000000000..c10afcf23a
--- /dev/null
+++ b/src/test/modules/snapshot_too_old/test_sto--1.0.sql
@@ -0,0 +1,14 @@
+/* src/test/modules/snapshot_too_old/test_sto--1.0.sql */
+
+-- complain if script is sourced in psql, rather than via CREATE EXTENSION
+\echo Use "CREATE EXTENSION test_sto" to load this file. \quit
+
+CREATE FUNCTION test_sto_clobber_snapshot_timestamp(now timestamptz)
+RETURNS VOID
+AS 'MODULE_PATHNAME', 'test_sto_clobber_snapshot_timestamp'
+LANGUAGE C STRICT;
+
+CREATE FUNCTION test_sto_reset_all_state()
+RETURNS VOID
+AS 'MODULE_PATHNAME', 'test_sto_reset_all_state'
+LANGUAGE C STRICT;
diff --git a/src/test/modules/snapshot_too_old/test_sto.c b/src/test/modules/snapshot_too_old/test_sto.c
new file mode 100644
index 0000000000..f6c9a1a000
--- /dev/null
+++ b/src/test/modules/snapshot_too_old/test_sto.c
@@ -0,0 +1,74 @@
+/*-------------------------------------------------------------------------
+ *
+ * test_sto.c
+ *	  Functions to support isolation tests for snapshot too old.
+ *
+ * These functions are not intended for use in a production database and
+ * could cause corruption.
+ *
+ * Copyright (c) 2020, PostgreSQL Global Development Group
+ *
+ *	  src/test/modules/snapshot_too_old/test_sto.c
+ *-------------------------------------------------------------------------
+ */
+#include "postgres.h"
+
+#include "funcapi.h"
+#include "storage/lwlock.h"
+#include "utils/old_snapshot.h"
+#include "utils/snapmgr.h"
+#include "utils/timestamp.h"
+
+PG_MODULE_MAGIC;
+PG_FUNCTION_INFO_V1(test_sto_reset_all_state);
+PG_FUNCTION_INFO_V1(test_sto_clobber_snapshot_timestamp);
+
+/*
+ * Revert to initial state.  This is not safe except in carefully
+ * controlled tests.
+ */
+Datum
+test_sto_reset_all_state(PG_FUNCTION_ARGS)
+{
+
+	LWLockAcquire(OldSnapshotTimeMapLock, LW_EXCLUSIVE);
+	oldSnapshotControl->count_used = 0;
+	oldSnapshotControl->current_timestamp = 0;
+	oldSnapshotControl->head_offset = 0;
+	oldSnapshotControl->head_timestamp = 0;
+	LWLockRelease(OldSnapshotTimeMapLock);
+
+	SpinLockAcquire(&oldSnapshotControl->mutex_latest_xmin);
+	oldSnapshotControl->latest_xmin = InvalidTransactionId;
+	oldSnapshotControl->next_map_update = 0;
+	SpinLockRelease(&oldSnapshotControl->mutex_latest_xmin);
+
+	SpinLockAcquire(&oldSnapshotControl->mutex_current);
+	oldSnapshotControl->current_timestamp = 0;
+	SpinLockRelease(&oldSnapshotControl->mutex_current);
+
+	SpinLockAcquire(&oldSnapshotControl->mutex_threshold);
+	oldSnapshotControl->threshold_timestamp = 0;
+	oldSnapshotControl->threshold_xid = InvalidTransactionId;
+	SpinLockRelease(&oldSnapshotControl->mutex_threshold);
+
+	PG_RETURN_NULL();
+}
+
+/*
+ * Update the minimum time used in snapshot-too-old code.  If set ahead of the
+ * current wall clock time (for example, the year 3000), this allows testing
+ * with arbitrary times.  This is not safe except in carefully controlled
+ * tests.
+ */
+Datum
+test_sto_clobber_snapshot_timestamp(PG_FUNCTION_ARGS)
+{
+	TimestampTz new_current_timestamp = PG_GETARG_TIMESTAMPTZ(0);
+
+	SpinLockAcquire(&oldSnapshotControl->mutex_current);
+	oldSnapshotControl->current_timestamp = new_current_timestamp;
+	SpinLockRelease(&oldSnapshotControl->mutex_current);
+
+	PG_RETURN_NULL();
+}
diff --git a/src/test/modules/snapshot_too_old/test_sto.control b/src/test/modules/snapshot_too_old/test_sto.control
new file mode 100644
index 0000000000..e497e5450e
--- /dev/null
+++ b/src/test/modules/snapshot_too_old/test_sto.control
@@ -0,0 +1,5 @@
+# test_sto test module
+comment = 'functions for internal testing of snapshot too old errors'
+default_version = '1.0'
+module_pathname = '$libdir/test_sto'
+relocatable = true
-- 
2.20.1

From 1a1168caa9d4bfe5b36ab14ed31ae0ef98d267e8 Mon Sep 17 00:00:00 2001
From: Thomas Munro <thomas.mu...@gmail.com>
Date: Mon, 20 Apr 2020 17:05:42 +1200
Subject: [PATCH v4 5/5] Truncate snapshot-too-old time map when CLOG is
 truncated.

It's not safe to leave xids in the map that have wrapped around.

Reported-by: Andres Freund
---
 src/backend/commands/vacuum.c                 |  3 +
 src/backend/utils/time/snapmgr.c              | 21 +++++
 src/include/utils/snapmgr.h                   |  1 +
 src/test/modules/snapshot_too_old/Makefile    |  4 +-
 .../snapshot_too_old/t/001_truncate.pl        | 81 +++++++++++++++++++
 5 files changed, 109 insertions(+), 1 deletion(-)
 create mode 100644 src/test/modules/snapshot_too_old/t/001_truncate.pl

diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.c
index 5a110edb07..37ead45fa5 100644
--- a/src/backend/commands/vacuum.c
+++ b/src/backend/commands/vacuum.c
@@ -1627,6 +1627,9 @@ vac_truncate_clog(TransactionId frozenXID,
 	 */
 	AdvanceOldestCommitTsXid(frozenXID);
 
+	/* Make sure snapshot_too_old drops old XIDs. */
+	TruncateOldSnapshotTimeMapping(frozenXID);
+
 	/*
 	 * Truncate CLOG, multixact and CommitTs to the oldest computed value.
 	 */
diff --git a/src/backend/utils/time/snapmgr.c b/src/backend/utils/time/snapmgr.c
index 19e6c52b80..edb47c9664 100644
--- a/src/backend/utils/time/snapmgr.c
+++ b/src/backend/utils/time/snapmgr.c
@@ -1974,6 +1974,27 @@ MaintainOldSnapshotTimeMapping(TimestampTz whenTaken, TransactionId xmin)
 }
 
 
+/*
+ * Remove old xids from the timing map, so the CLOG can be truncated.
+ */
+void
+TruncateOldSnapshotTimeMapping(TransactionId frozenXID)
+{
+	LWLockAcquire(OldSnapshotTimeMapLock, LW_EXCLUSIVE);
+	while (oldSnapshotControl->count_used > 0 &&
+		   TransactionIdPrecedes(oldSnapshotControl->xid_by_minute[oldSnapshotControl->head_offset],
+								 frozenXID))
+	{
+		oldSnapshotControl->head_timestamp += USECS_PER_MINUTE;
+		oldSnapshotControl->head_offset =
+			(oldSnapshotControl->head_offset + 1) %
+			OLD_SNAPSHOT_TIME_MAP_ENTRIES;
+		oldSnapshotControl->count_used--;
+	}
+	LWLockRelease(OldSnapshotTimeMapLock);
+}
+
+
 /*
  * Setup a snapshot that replaces normal catalog snapshots that allows catalog
  * access to behave just like it did at a certain point in the past.
diff --git a/src/include/utils/snapmgr.h b/src/include/utils/snapmgr.h
index b28d13ce84..4f53aad956 100644
--- a/src/include/utils/snapmgr.h
+++ b/src/include/utils/snapmgr.h
@@ -135,6 +135,7 @@ extern TransactionId TransactionIdLimitedForOldSnapshots(TransactionId recentXmi
 														 Relation relation);
 extern void MaintainOldSnapshotTimeMapping(TimestampTz whenTaken,
 										   TransactionId xmin);
+extern void TruncateOldSnapshotTimeMapping(TransactionId frozenXID);
 
 extern char *ExportSnapshot(Snapshot snapshot);
 
diff --git a/src/test/modules/snapshot_too_old/Makefile b/src/test/modules/snapshot_too_old/Makefile
index 81836e9953..f919944984 100644
--- a/src/test/modules/snapshot_too_old/Makefile
+++ b/src/test/modules/snapshot_too_old/Makefile
@@ -9,7 +9,7 @@ EXTENSION = test_sto
 DATA = test_sto--1.0.sql
 PGDESCFILE = "test_sto -- internal testing for snapshot too old errors"
 
-EXTRA_INSTALL = contrib/pg_visibility
+EXTRA_INSTALL = contrib/pg_visibility contrib/old_snapshot
 
 ISOLATION = sto_using_cursor sto_using_select sto_using_hash_index
 ISOLATION_OPTS = --temp-config $(top_srcdir)/src/test/modules/snapshot_too_old/sto.conf
@@ -19,6 +19,8 @@ ISOLATION_OPTS = --temp-config $(top_srcdir)/src/test/modules/snapshot_too_old/s
 # because it'd be dangerous on a production system.
 NO_INSTALLCHECK = 1
 
+TAP_TESTS = 1
+
 ifdef USE_PGXS
 PG_CONFIG = pg_config
 PGXS := $(shell $(PG_CONFIG) --pgxs)
diff --git a/src/test/modules/snapshot_too_old/t/001_truncate.pl b/src/test/modules/snapshot_too_old/t/001_truncate.pl
new file mode 100644
index 0000000000..c3bff45f65
--- /dev/null
+++ b/src/test/modules/snapshot_too_old/t/001_truncate.pl
@@ -0,0 +1,81 @@
+# Test truncation of the old snapshot time mapping, to check
+# that we can't get into trouble when xids wrap around.
+use strict;
+use warnings;
+use PostgresNode;
+use TestLib;
+use Test::More tests => 6;
+
+my $node = get_new_node('master');
+$node->init;
+$node->append_conf("postgresql.conf", "timezone = UTC");
+$node->append_conf("postgresql.conf", "old_snapshot_threshold=10");
+$node->append_conf("postgresql.conf", "max_prepared_transactions=10");
+$node->start;
+$node->psql('postgres', 'update pg_database set datallowconn = true');
+$node->psql('postgres', 'create extension old_snapshot');
+$node->psql('postgres', 'create extension test_sto');
+
+note "check time map is truncated when CLOG is";
+
+# build up a time map with 4 entries
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:00:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:01:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:02:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:03:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+my $count;
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 4, "expected to have 4 entries in the old snapshot time map");
+
+# now cause frozen XID to advance
+$node->psql('postgres', 'vacuum freeze');
+$node->psql('template0', 'vacuum freeze');
+$node->psql('template1', 'vacuum freeze');
+
+# we expect all XIDs to have been truncated
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 0, "expected to have 0 entries in the old snapshot time map");
+
+# put two more in the map
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:04:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:05:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 2, "expected to have 2 entries in the old snapshot time map");
+
+# prepare a transaction, to stop xmin from getting further ahead
+$node->psql('postgres', "begin; select pg_current_xact_id(); prepare transaction 'tx1'");
+
+# add 16 more minutes (this tests wrapping around the mapping array, which is of size 10 + 10)...
+$node->psql('postgres', "select test_sto_clobber_snapshot_timestamp('3000-01-01 00:21:00Z')");
+$node->psql('postgres', "select pg_current_xact_id()");
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 18, "expected to have 18 entries in the old snapshot time map");
+
+# now cause frozen XID to advance
+$node->psql('postgres', 'vacuum freeze');
+$node->psql('template0', 'vacuum freeze');
+$node->psql('template1', 'vacuum freeze');
+
+# this should leave just 16
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 16, "expected to have 16 entries in the old snapshot time map");
+
+# commit tx1, and then freeze again to get rid of all of them
+$node->psql('postgres', "commit prepared 'tx1'");
+
+# now cause frozen XID to advance
+$node->psql('postgres', 'vacuum freeze');
+$node->psql('template0', 'vacuum freeze');
+$node->psql('template1', 'vacuum freeze');
+
+# we should now be back to empty
+$node->psql('postgres', "select count(*) from pg_old_snapshot_time_mapping()", stdout => \$count);
+is($count, 0, "expected to have 0 entries in the old snapshot time map");
+
+$node->stop;
-- 
2.20.1

Reply via email to