From 60690a6fe8351995b1eeb9a53f2b634c3bce3a3d Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Fri, 4 Mar 2016 16:20:44 -0500 Subject: [PATCH] Make stats regression test robust in the face of parallel query. Historically, the wait_for_stats() function in this test has simply checked for a report of an indexscan on tenk2, corresponding to the last command issued before we expect stats updates to appear. However, with parallel query that indexscan could be done by a parallel worker that will emit its stats counters to the collector before the session's main backend does (a full second before, in fact, thanks to the "pg_sleep(1.0)" added by commit 957d08c81f9cc277). That leaves a sizable window in which an autovacuum-triggered write of the stats files would present a state in which the indexscan on tenk2 appears to have been done, but none of the write updates performed by the test have been. This is evidently the explanation for intermittent failures seen by me and on buildfarm member mandrill. To fix, we should check separately for both the tenk2 seqscan and indexscan counts, since those might be reported by different processes that could be delayed arbitrarily on an overloaded test machine. And we need to check for at least one update-related count. If we ever allow parallel workers to do writes, this will get even more complicated ... but in view of all the other hard problems that will entail, I don't feel a need to solve this one today. Per research by Rahila Syed and myself; part of this patch is Rahila's. --- src/test/regress/expected/stats.out | 26 +++++++++++++++++++++----- src/test/regress/sql/stats.sql | 26 +++++++++++++++++++++----- 2 files changed, 42 insertions(+), 10 deletions(-) diff --git a/src/test/regress/expected/stats.out b/src/test/regress/expected/stats.out index f5be70fe7c..a811265d69 100644 --- a/src/test/regress/expected/stats.out +++ b/src/test/regress/expected/stats.out @@ -37,17 +37,33 @@ SELECT t.seq_scan, t.seq_tup_read, t.idx_scan, t.idx_tup_fetch, create function wait_for_stats() returns void as $$ declare start_time timestamptz := clock_timestamp(); - updated bool; + updated1 bool; + updated2 bool; + updated3 bool; begin -- we don't want to wait forever; loop will exit after 30 seconds for i in 1 .. 300 loop - -- check to see if indexscan has been sensed - SELECT (st.idx_scan >= pr.idx_scan + 1) INTO updated + -- With parallel query, the seqscan and indexscan on tenk2 might be done + -- in parallel worker processes, which will send their stats counters + -- asynchronously to what our own session does. So we must check for + -- those counts to be registered separately from the update counts. + + -- check to see if seqscan has been sensed + SELECT (st.seq_scan >= pr.seq_scan + 1) INTO updated1 FROM pg_stat_user_tables AS st, pg_class AS cl, prevstats AS pr WHERE st.relname='tenk2' AND cl.relname='tenk2'; - exit when updated; + -- check to see if indexscan has been sensed + SELECT (st.idx_scan >= pr.idx_scan + 1) INTO updated2 + FROM pg_stat_user_tables AS st, pg_class AS cl, prevstats AS pr + WHERE st.relname='tenk2' AND cl.relname='tenk2'; + + -- check to see if updates have been sensed + SELECT (n_tup_ins > 0) INTO updated3 + FROM pg_stat_user_tables WHERE relname='trunc_stats_test'; + + exit when updated1 and updated2 and updated3; -- wait a little perform pg_sleep(0.1); @@ -127,7 +143,7 @@ SELECT count(*) FROM tenk2 WHERE unique1 = 1; 1 (1 row) --- force the rate-limiting logic in pgstat_report_tabstat() to time out +-- force the rate-limiting logic in pgstat_report_stat() to time out -- and send a message SELECT pg_sleep(1.0); pg_sleep diff --git a/src/test/regress/sql/stats.sql b/src/test/regress/sql/stats.sql index cd2d5927bc..b3e2efa535 100644 --- a/src/test/regress/sql/stats.sql +++ b/src/test/regress/sql/stats.sql @@ -32,17 +32,33 @@ SELECT t.seq_scan, t.seq_tup_read, t.idx_scan, t.idx_tup_fetch, create function wait_for_stats() returns void as $$ declare start_time timestamptz := clock_timestamp(); - updated bool; + updated1 bool; + updated2 bool; + updated3 bool; begin -- we don't want to wait forever; loop will exit after 30 seconds for i in 1 .. 300 loop - -- check to see if indexscan has been sensed - SELECT (st.idx_scan >= pr.idx_scan + 1) INTO updated + -- With parallel query, the seqscan and indexscan on tenk2 might be done + -- in parallel worker processes, which will send their stats counters + -- asynchronously to what our own session does. So we must check for + -- those counts to be registered separately from the update counts. + + -- check to see if seqscan has been sensed + SELECT (st.seq_scan >= pr.seq_scan + 1) INTO updated1 FROM pg_stat_user_tables AS st, pg_class AS cl, prevstats AS pr WHERE st.relname='tenk2' AND cl.relname='tenk2'; - exit when updated; + -- check to see if indexscan has been sensed + SELECT (st.idx_scan >= pr.idx_scan + 1) INTO updated2 + FROM pg_stat_user_tables AS st, pg_class AS cl, prevstats AS pr + WHERE st.relname='tenk2' AND cl.relname='tenk2'; + + -- check to see if updates have been sensed + SELECT (n_tup_ins > 0) INTO updated3 + FROM pg_stat_user_tables WHERE relname='trunc_stats_test'; + + exit when updated1 and updated2 and updated3; -- wait a little perform pg_sleep(0.1); @@ -121,7 +137,7 @@ SELECT count(*) FROM tenk2; -- do an indexscan SELECT count(*) FROM tenk2 WHERE unique1 = 1; --- force the rate-limiting logic in pgstat_report_tabstat() to time out +-- force the rate-limiting logic in pgstat_report_stat() to time out -- and send a message SELECT pg_sleep(1.0);