public inbox for [email protected]
help / color / mirror / Atom feedFrom: Anton A. Melnikov <[email protected]>
To: [email protected]
Subject: Possible fails in pg_stat_statements test
Date: Fri, 14 Jan 2022 11:11:07 +0300
Message-ID: <[email protected]> (raw)
Hello,
There are some places in the pg_state_statement's regress test where the
bool result of comparison between the number of rows obtained and
wal_records generated by query should be displayed.
Now counting the number of wal_records for some query in
pg_state_statement is done by the global pgWalUsage.wal_records counter
difference calculation.
During query execution the extra wal_records may appear that are not
relate to the query.
There are two reasons why this might happen:
1) Owing to the hit into pruning of some page in optional pruning
function (heap_page_prune_opt()).
2) When a new page is required for a new xid in clog and
WriteZeroPageXlogRec() was called.
In both cases an extra wal record with zero xl_xid is generated, so
wal_records counter gives an incremented value for this query and
pg_stat_statement test will fail.
This patch introduces an additional counter of wal records not related
to the query being executed.
Due to this counter pg_stat_statement finds out the number of wal
records that are not relevant to the query and does not include them in
the per query statistic.
This removes the possibility of the error described above.
There is a way to reproduce this error when patch is not applied:
1) start server with "shared_preload_libraries = 'pg_stat_statements'"
string in the postgresql.conf;
2) replace makefile in contrib/pg_stat_statements with attached one;
3) replace test file
contrib/pg_stat_statements/sql/pg_stat_statements.sql and expected
results contrib/pg_stat_statements/expected/pg_stat_statements.out
with shorter versions from attached files;
4) copy test.sh to contrib/pg_stat_statements and make sure that PGHOME
point to your server;
5) cd to contrib/pg_stat_statements and execute:
export ITER=1 && while ./start.sh || break; export ITER=$(($ITER+1)); do
:; done
Usually 100-200 iterations will be enough.
To catch the error more faster one can add wal_records column to SELECT
in line 26 of contrib/pg_stat_statements/sql/pg_stat_statements.sql as
followes:
SELECT query, calls, rows, wal_records,
and replace the contrib/pg_stat_statements/expected/pg_stat_statements.out
with attached pg_stat_statements-fast.out
With best regards,
--
Anton A. Melnikov
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
# contrib/pg_stat_statements/Makefile
MODULE_big = pg_stat_statements
OBJS = \
$(WIN32RES) \
pg_stat_statements.o
EXTENSION = pg_stat_statements
DATA = pg_stat_statements--1.4.sql pg_stat_statements--1.8--1.9.sql \
pg_stat_statements--1.7--1.8.sql pg_stat_statements--1.6--1.7.sql \
pg_stat_statements--1.5--1.6.sql pg_stat_statements--1.4--1.5.sql \
pg_stat_statements--1.3--1.4.sql pg_stat_statements--1.2--1.3.sql \
pg_stat_statements--1.1--1.2.sql pg_stat_statements--1.0--1.1.sql
PGFILEDESC = "pg_stat_statements - execution statistics of SQL statements"
LDFLAGS_SL += $(filter -lm, $(LIBS))
REGRESS_OPTS = --temp-config $(top_srcdir)/contrib/pg_stat_statements/pg_stat_statements.conf
REGRESS = pg_stat_statements oldextversions
REGRESS = $(shell printf "pg_stat_statements %.0s" `seq 1 100`) oldextversions
# Disabled because these tests require "shared_preload_libraries=pg_stat_statements",
# which typical installcheck users do not have (e.g. buildfarm clients).
# NO_INSTALLCHECK = 1
ifdef USE_PGXS
PG_CONFIG = pg_config
PGXS := $(shell $(PG_CONFIG) --pgxs)
include $(PGXS)
else
subdir = contrib/pg_stat_statements
top_builddir = ../..
include $(top_builddir)/src/Makefile.global
include $(top_srcdir)/contrib/contrib-global.mk
endif
CREATE EXTENSION pg_stat_statements;
--
-- simple and compound statements
--
SET pg_stat_statements.track_utility = FALSE;
SET pg_stat_statements.track_planning = TRUE;
SELECT pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
(1 row)
-- utility "create table" should not be shown
CREATE TABLE pgss_test (a int, b char(20));
INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
DELETE FROM pgss_test WHERE a > 9;
-- DROP test table
SET pg_stat_statements.track_utility = TRUE;
-- SELECT wal_records FROM pg_stat_wal;
-- select txid_current();
DROP TABLE pgss_test;
-- select txid_current();
-- SELECT wal_records FROM pg_stat_wal;
SET pg_stat_statements.track_utility = FALSE;
-- Check WAL is generated for the above statements
SELECT query, calls, rows,
wal_bytes > 0 as wal_bytes_generated,
wal_records > 0 as wal_records_generated,
wal_records = rows as wal_records_as_rows
FROM pg_stat_statements ORDER BY query COLLATE "C";
query | calls | rows | wal_bytes_generated | wal_records_generated | wal_records_as_rows
-----------------------------------------------------------+-------+------+---------------------+-----------------------+---------------------
DELETE FROM pgss_test WHERE a > $1 | 1 | 1 | t | t | t
DROP TABLE pgss_test | 1 | 0 | t | t | f
INSERT INTO pgss_test VALUES(generate_series($1, $2), $3) | 1 | 10 | t | t | t
SELECT pg_stat_statements_reset() | 1 | 1 | f | f | f
SELECT query, calls, rows, +| 0 | 0 | f | f | t
wal_bytes > $1 as wal_bytes_generated, +| | | | |
wal_records > $2 as wal_records_generated, +| | | | |
wal_records = rows as wal_records_as_rows +| | | | |
FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | |
SET pg_stat_statements.track_utility = FALSE | 1 | 0 | f | f | t
UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | t | t | t
(7 rows)
DROP EXTENSION pg_stat_statements;
CREATE EXTENSION pg_stat_statements;
--
-- simple and compound statements
--
SET pg_stat_statements.track_utility = FALSE;
SET pg_stat_statements.track_planning = TRUE;
SELECT pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
(1 row)
-- utility "create table" should not be shown
CREATE TABLE pgss_test (a int, b char(20));
INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
DELETE FROM pgss_test WHERE a > 9;
-- DROP test table
SET pg_stat_statements.track_utility = TRUE;
-- SELECT wal_records FROM pg_stat_wal;
-- select txid_current();
DROP TABLE pgss_test;
-- select txid_current();
-- SELECT wal_records FROM pg_stat_wal;
SET pg_stat_statements.track_utility = FALSE;
-- Check WAL is generated for the above statements
SELECT query, calls, rows, wal_records,
wal_bytes > 0 as wal_bytes_generated,
wal_records > 0 as wal_records_generated,
wal_records = rows as wal_records_as_rows
FROM pg_stat_statements ORDER BY query COLLATE "C";
query | calls | rows | wal_records | wal_bytes_generated | wal_records_generated | wal_records_as_rows
-----------------------------------------------------------+-------+------+-------------+---------------------+-----------------------+---------------------
DELETE FROM pgss_test WHERE a > $1 | 1 | 1 | 1 | t | t | t
DROP TABLE pgss_test | 1 | 0 | 15 | t | t | f
INSERT INTO pgss_test VALUES(generate_series($1, $2), $3) | 1 | 10 | 10 | t | t | t
SELECT pg_stat_statements_reset() | 1 | 1 | 0 | f | f | f
SELECT query, calls, rows, wal_records, +| 0 | 0 | 0 | f | f | t
wal_bytes > $1 as wal_bytes_generated, +| | | | | |
wal_records > $2 as wal_records_generated, +| | | | | |
wal_records = rows as wal_records_as_rows +| | | | | |
FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | | |
SET pg_stat_statements.track_utility = FALSE | 1 | 0 | 0 | f | f | t
UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | 3 | t | t | t
(7 rows)
DROP EXTENSION pg_stat_statements;
Attachments:
[text/x-patch] v1-0001-Fix-possible-fails-in-pg_stat_statements-test.patch (4.0K, ../[email protected]/2-v1-0001-Fix-possible-fails-in-pg_stat_statements-test.patch)
download | inline diff:
commit 3f4659a8d8a390bb24fbc6f82a6add7949fbebe2
Author: Anton A. Melnikov <[email protected]>
Date: Fri Jan 14 10:54:35 2022 +0300
Fix possible fails in pg_stat_statements test via taking into account non-query wal records.
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 082bfa8f77..bd437aefc3 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -1370,7 +1370,7 @@ pgss_store(const char *query, uint64 queryId,
e->counters.blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_read_time);
e->counters.blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_write_time);
e->counters.usage += USAGE_EXEC(total_time);
- e->counters.wal_records += walusage->wal_records;
+ e->counters.wal_records += (walusage->wal_records - walusage->non_query_wal_recs);
e->counters.wal_fpi += walusage->wal_fpi;
e->counters.wal_bytes += walusage->wal_bytes;
diff --git a/src/backend/access/heap/pruneheap.c b/src/backend/access/heap/pruneheap.c
index 3201fcc52b..41f17ab97c 100644
--- a/src/backend/access/heap/pruneheap.c
+++ b/src/backend/access/heap/pruneheap.c
@@ -20,6 +20,7 @@
#include "access/transam.h"
#include "access/xlog.h"
#include "catalog/catalog.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pgstat.h"
#include "storage/bufmgr.h"
@@ -208,6 +209,11 @@ heap_page_prune_opt(Relation relation, Buffer buffer)
ndeleted = heap_page_prune(relation, buffer, vistest, limited_xmin,
limited_ts, &nnewlpdead, NULL);
+ /* Take into account that heap_page_prune() just generated a new
+ * wal record with zero xl_xid that is not related to current query.
+ */
+ pgWalUsage.non_query_wal_recs++;
+
/*
* Report the number of tuples reclaimed to pgstats. This is
* ndeleted minus the number of newly-LP_DEAD-set items.
diff --git a/src/backend/access/transam/clog.c b/src/backend/access/transam/clog.c
index de787c3d37..e944fc3b1a 100644
--- a/src/backend/access/transam/clog.c
+++ b/src/backend/access/transam/clog.c
@@ -38,6 +38,7 @@
#include "access/xlog.h"
#include "access/xloginsert.h"
#include "access/xlogutils.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pg_trace.h"
#include "pgstat.h"
@@ -955,6 +956,12 @@ WriteZeroPageXlogRec(int pageno)
XLogBeginInsert();
XLogRegisterData((char *) (&pageno), sizeof(int));
(void) XLogInsert(RM_CLOG_ID, CLOG_ZEROPAGE);
+
+ /*
+ * Consider that a new unrelated to current query wal record
+ * with zero xl_xid has just been created.
+ */
+ pgWalUsage.non_query_wal_recs++;
}
/*
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index c5ff02a842..214fb3cc45 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -268,6 +268,7 @@ WalUsageAdd(WalUsage *dst, WalUsage *add)
dst->wal_bytes += add->wal_bytes;
dst->wal_records += add->wal_records;
dst->wal_fpi += add->wal_fpi;
+ dst->non_query_wal_recs += add->non_query_wal_recs;
}
void
@@ -276,4 +277,5 @@ WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
dst->wal_bytes += add->wal_bytes - sub->wal_bytes;
dst->wal_records += add->wal_records - sub->wal_records;
dst->wal_fpi += add->wal_fpi - sub->wal_fpi;
+ dst->non_query_wal_recs += add->non_query_wal_recs - sub->non_query_wal_recs;
}
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 1b7157bdd1..0d83f37a3c 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -49,6 +49,11 @@ typedef struct WalUsage
int64 wal_records; /* # of WAL records produced */
int64 wal_fpi; /* # of WAL full page images produced */
uint64 wal_bytes; /* size of WAL records produced */
+ /*
+ * Number of WAL records unrelated to current query. In particular due to
+ * heap_page_prune_opt() or WriteZeroPageXlogRec().
+ */
+ int64 non_query_wal_recs;
} WalUsage;
/* Flag bits included in InstrAlloc's instrument_options bitmask */
[text/plain] Makefile (1.2K, ../[email protected]/3-Makefile)
download | inline:
# contrib/pg_stat_statements/Makefile
MODULE_big = pg_stat_statements
OBJS = \
$(WIN32RES) \
pg_stat_statements.o
EXTENSION = pg_stat_statements
DATA = pg_stat_statements--1.4.sql pg_stat_statements--1.8--1.9.sql \
pg_stat_statements--1.7--1.8.sql pg_stat_statements--1.6--1.7.sql \
pg_stat_statements--1.5--1.6.sql pg_stat_statements--1.4--1.5.sql \
pg_stat_statements--1.3--1.4.sql pg_stat_statements--1.2--1.3.sql \
pg_stat_statements--1.1--1.2.sql pg_stat_statements--1.0--1.1.sql
PGFILEDESC = "pg_stat_statements - execution statistics of SQL statements"
LDFLAGS_SL += $(filter -lm, $(LIBS))
REGRESS_OPTS = --temp-config $(top_srcdir)/contrib/pg_stat_statements/pg_stat_statements.conf
REGRESS = pg_stat_statements oldextversions
REGRESS = $(shell printf "pg_stat_statements %.0s" `seq 1 100`) oldextversions
# Disabled because these tests require "shared_preload_libraries=pg_stat_statements",
# which typical installcheck users do not have (e.g. buildfarm clients).
# NO_INSTALLCHECK = 1
ifdef USE_PGXS
PG_CONFIG = pg_config
PGXS := $(shell $(PG_CONFIG) --pgxs)
include $(PGXS)
else
subdir = contrib/pg_stat_statements
top_builddir = ../..
include $(top_builddir)/src/Makefile.global
include $(top_srcdir)/contrib/contrib-global.mk
endif
[application/sql] pg_stat_statements.sql (989B, ../[email protected]/4-pg_stat_statements.sql)
download
[text/plain] pg_stat_statements.out (2.6K, ../[email protected]/5-pg_stat_statements.out)
download | inline:
CREATE EXTENSION pg_stat_statements;
--
-- simple and compound statements
--
SET pg_stat_statements.track_utility = FALSE;
SET pg_stat_statements.track_planning = TRUE;
SELECT pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
(1 row)
-- utility "create table" should not be shown
CREATE TABLE pgss_test (a int, b char(20));
INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
DELETE FROM pgss_test WHERE a > 9;
-- DROP test table
SET pg_stat_statements.track_utility = TRUE;
-- SELECT wal_records FROM pg_stat_wal;
-- select txid_current();
DROP TABLE pgss_test;
-- select txid_current();
-- SELECT wal_records FROM pg_stat_wal;
SET pg_stat_statements.track_utility = FALSE;
-- Check WAL is generated for the above statements
SELECT query, calls, rows,
wal_bytes > 0 as wal_bytes_generated,
wal_records > 0 as wal_records_generated,
wal_records = rows as wal_records_as_rows
FROM pg_stat_statements ORDER BY query COLLATE "C";
query | calls | rows | wal_bytes_generated | wal_records_generated | wal_records_as_rows
-----------------------------------------------------------+-------+------+---------------------+-----------------------+---------------------
DELETE FROM pgss_test WHERE a > $1 | 1 | 1 | t | t | t
DROP TABLE pgss_test | 1 | 0 | t | t | f
INSERT INTO pgss_test VALUES(generate_series($1, $2), $3) | 1 | 10 | t | t | t
SELECT pg_stat_statements_reset() | 1 | 1 | f | f | f
SELECT query, calls, rows, +| 0 | 0 | f | f | t
wal_bytes > $1 as wal_bytes_generated, +| | | | |
wal_records > $2 as wal_records_generated, +| | | | |
wal_records = rows as wal_records_as_rows +| | | | |
FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | |
SET pg_stat_statements.track_utility = FALSE | 1 | 0 | f | f | t
UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | t | t | t
(7 rows)
DROP EXTENSION pg_stat_statements;
[application/x-shellscript] start.sh (267B, ../[email protected]/6-start.sh)
download
[text/plain] pg_stat_statements-fast.out (2.8K, ../[email protected]/7-pg_stat_statements-fast.out)
download | inline:
CREATE EXTENSION pg_stat_statements;
--
-- simple and compound statements
--
SET pg_stat_statements.track_utility = FALSE;
SET pg_stat_statements.track_planning = TRUE;
SELECT pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------
(1 row)
-- utility "create table" should not be shown
CREATE TABLE pgss_test (a int, b char(20));
INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
DELETE FROM pgss_test WHERE a > 9;
-- DROP test table
SET pg_stat_statements.track_utility = TRUE;
-- SELECT wal_records FROM pg_stat_wal;
-- select txid_current();
DROP TABLE pgss_test;
-- select txid_current();
-- SELECT wal_records FROM pg_stat_wal;
SET pg_stat_statements.track_utility = FALSE;
-- Check WAL is generated for the above statements
SELECT query, calls, rows, wal_records,
wal_bytes > 0 as wal_bytes_generated,
wal_records > 0 as wal_records_generated,
wal_records = rows as wal_records_as_rows
FROM pg_stat_statements ORDER BY query COLLATE "C";
query | calls | rows | wal_records | wal_bytes_generated | wal_records_generated | wal_records_as_rows
-----------------------------------------------------------+-------+------+-------------+---------------------+-----------------------+---------------------
DELETE FROM pgss_test WHERE a > $1 | 1 | 1 | 1 | t | t | t
DROP TABLE pgss_test | 1 | 0 | 15 | t | t | f
INSERT INTO pgss_test VALUES(generate_series($1, $2), $3) | 1 | 10 | 10 | t | t | t
SELECT pg_stat_statements_reset() | 1 | 1 | 0 | f | f | f
SELECT query, calls, rows, wal_records, +| 0 | 0 | 0 | f | f | t
wal_bytes > $1 as wal_bytes_generated, +| | | | | |
wal_records > $2 as wal_records_generated, +| | | | | |
wal_records = rows as wal_records_as_rows +| | | | | |
FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | | |
SET pg_stat_statements.track_utility = FALSE | 1 | 0 | 0 | f | f | t
UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | 3 | t | t | t
(7 rows)
DROP EXTENSION pg_stat_statements;
view thread (2+ messages)
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]
Subject: Re: Possible fails in pg_stat_statements test
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