Skip to content

Commit 700221c

Browse files
committed
Add pg_session_buffer_usage contrib module
This is intended for testing instrumentation related logic as it pertains to the top level stack that is maintained as a running total. There is currently no in-core user that utilizes the top-level values in this manner, and especially during abort situations this helps ensure we don't lose activity due to incorrect handling of unfinalized node stacks.
1 parent e60660a commit 700221c

9 files changed

Lines changed: 777 additions & 0 deletions

File tree

contrib/Makefile

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ SUBDIRS = \
3636
pg_overexplain \
3737
pg_plan_advice \
3838
pg_prewarm \
39+
pg_session_buffer_usage \
3940
pg_stat_statements \
4041
pg_surgery \
4142
pg_trgm \

contrib/meson.build

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@ subdir('pg_overexplain')
5151
subdir('pg_plan_advice')
5252
subdir('pg_prewarm')
5353
subdir('pgrowlocks')
54+
subdir('pg_session_buffer_usage')
5455
subdir('pg_stat_statements')
5556
subdir('pgstattuple')
5657
subdir('pg_surgery')
Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,23 @@
1+
# contrib/pg_session_buffer_usage/Makefile
2+
3+
MODULE_big = pg_session_buffer_usage
4+
OBJS = \
5+
$(WIN32RES) \
6+
pg_session_buffer_usage.o
7+
8+
EXTENSION = pg_session_buffer_usage
9+
DATA = pg_session_buffer_usage--1.0.sql
10+
PGFILEDESC = "pg_session_buffer_usage - show buffer usage statistics for the current session"
11+
12+
REGRESS = pg_session_buffer_usage
13+
14+
ifdef USE_PGXS
15+
PG_CONFIG = pg_config
16+
PGXS := $(shell $(PG_CONFIG) --pgxs)
17+
include $(PGXS)
18+
else
19+
subdir = contrib/pg_session_buffer_usage
20+
top_builddir = ../..
21+
include $(top_builddir)/src/Makefile.global
22+
include $(top_srcdir)/contrib/contrib-global.mk
23+
endif
Lines changed: 342 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,342 @@
1+
LOAD 'pg_session_buffer_usage';
2+
CREATE EXTENSION pg_session_buffer_usage;
3+
-- Verify all columns are non-negative
4+
SELECT count(*) = 1 AS ok FROM pg_session_buffer_usage()
5+
WHERE shared_blks_hit >= 0 AND shared_blks_read >= 0
6+
AND shared_blks_dirtied >= 0 AND shared_blks_written >= 0
7+
AND local_blks_hit >= 0 AND local_blks_read >= 0
8+
AND local_blks_dirtied >= 0 AND local_blks_written >= 0
9+
AND temp_blks_read >= 0 AND temp_blks_written >= 0
10+
AND shared_blk_read_time >= 0 AND shared_blk_write_time >= 0
11+
AND local_blk_read_time >= 0 AND local_blk_write_time >= 0
12+
AND temp_blk_read_time >= 0 AND temp_blk_write_time >= 0;
13+
ok
14+
----
15+
t
16+
(1 row)
17+
18+
-- Verify counters increase after buffer activity
19+
SELECT pg_session_buffer_usage_reset();
20+
pg_session_buffer_usage_reset
21+
-------------------------------
22+
23+
(1 row)
24+
25+
CREATE TEMP TABLE test_buf_activity (id int, data text);
26+
INSERT INTO test_buf_activity SELECT i, repeat('x', 100) FROM generate_series(1, 1000) AS i;
27+
SELECT count(*) FROM test_buf_activity;
28+
count
29+
-------
30+
1000
31+
(1 row)
32+
33+
SELECT local_blks_hit + local_blks_read > 0 AS blocks_increased
34+
FROM pg_session_buffer_usage();
35+
blocks_increased
36+
------------------
37+
t
38+
(1 row)
39+
40+
DROP TABLE test_buf_activity;
41+
-- Parallel query test
42+
CREATE TABLE par_dc_tab (a int, b char(200));
43+
INSERT INTO par_dc_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
44+
SELECT count(*) FROM par_dc_tab;
45+
count
46+
-------
47+
5000
48+
(1 row)
49+
50+
-- Measure serial scan delta (leader does all the work)
51+
SET max_parallel_workers_per_gather = 0;
52+
SELECT pg_session_buffer_usage_reset();
53+
pg_session_buffer_usage_reset
54+
-------------------------------
55+
56+
(1 row)
57+
58+
SELECT count(*) FROM par_dc_tab;
59+
count
60+
-------
61+
5000
62+
(1 row)
63+
64+
CREATE TEMP TABLE dc_serial_result AS
65+
SELECT shared_blks_hit AS serial_delta FROM pg_session_buffer_usage();
66+
-- Measure parallel scan delta with leader NOT participating in scanning.
67+
-- Workers do all table scanning; leader only runs the Gather node.
68+
SET parallel_setup_cost = 0;
69+
SET parallel_tuple_cost = 0;
70+
SET min_parallel_table_scan_size = 0;
71+
SET max_parallel_workers_per_gather = 2;
72+
SET parallel_leader_participation = off;
73+
SELECT pg_session_buffer_usage_reset();
74+
pg_session_buffer_usage_reset
75+
-------------------------------
76+
77+
(1 row)
78+
79+
SELECT count(*) FROM par_dc_tab;
80+
count
81+
-------
82+
5000
83+
(1 row)
84+
85+
-- Confirm we got a similar hit counter through parallel worker accumulation
86+
SELECT shared_blks_hit > s.serial_delta / 2 AND shared_blks_hit < s.serial_delta * 2
87+
AS leader_buffers_match
88+
FROM pg_session_buffer_usage(), dc_serial_result s;
89+
leader_buffers_match
90+
----------------------
91+
t
92+
(1 row)
93+
94+
RESET parallel_setup_cost;
95+
RESET parallel_tuple_cost;
96+
RESET min_parallel_table_scan_size;
97+
RESET max_parallel_workers_per_gather;
98+
RESET parallel_leader_participation;
99+
DROP TABLE par_dc_tab, dc_serial_result;
100+
--
101+
-- Abort/exception tests: verify buffer usage survives various error paths.
102+
--
103+
-- Rolled-back divide-by-zero under EXPLAIN ANALYZE
104+
CREATE TEMP TABLE exc_tab (a int, b char(20));
105+
SELECT pg_session_buffer_usage_reset();
106+
pg_session_buffer_usage_reset
107+
-------------------------------
108+
109+
(1 row)
110+
111+
EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
112+
WITH ins AS (INSERT INTO exc_tab VALUES (1, 'aaa') RETURNING a)
113+
SELECT a / 0 FROM ins;
114+
ERROR: division by zero
115+
SELECT local_blks_dirtied > 0 AS exception_buffers_visible
116+
FROM pg_session_buffer_usage();
117+
exception_buffers_visible
118+
---------------------------
119+
t
120+
(1 row)
121+
122+
DROP TABLE exc_tab;
123+
-- Unique constraint violation in regular query
124+
CREATE TEMP TABLE unique_tab (a int UNIQUE, b char(20));
125+
INSERT INTO unique_tab VALUES (1, 'first');
126+
SELECT pg_session_buffer_usage_reset();
127+
pg_session_buffer_usage_reset
128+
-------------------------------
129+
130+
(1 row)
131+
132+
INSERT INTO unique_tab VALUES (1, 'duplicate');
133+
ERROR: duplicate key value violates unique constraint "unique_tab_a_key"
134+
DETAIL: Key (a)=(1) already exists.
135+
SELECT local_blks_hit > 0 AS unique_violation_buffers_visible
136+
FROM pg_session_buffer_usage();
137+
unique_violation_buffers_visible
138+
----------------------------------
139+
t
140+
(1 row)
141+
142+
DROP TABLE unique_tab;
143+
-- Caught exception in PL/pgSQL subtransaction (BEGIN...EXCEPTION)
144+
CREATE TEMP TABLE subxact_tab (a int, b char(20));
145+
CREATE FUNCTION subxact_exc_func() RETURNS text AS $$
146+
BEGIN
147+
BEGIN
148+
EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
149+
WITH ins AS (INSERT INTO subxact_tab VALUES (1, ''aaa'') RETURNING a)
150+
SELECT a / 0 FROM ins';
151+
EXCEPTION WHEN division_by_zero THEN
152+
RETURN 'caught';
153+
END;
154+
RETURN 'not reached';
155+
END;
156+
$$ LANGUAGE plpgsql;
157+
SELECT pg_session_buffer_usage_reset();
158+
pg_session_buffer_usage_reset
159+
-------------------------------
160+
161+
(1 row)
162+
163+
SELECT subxact_exc_func();
164+
subxact_exc_func
165+
------------------
166+
caught
167+
(1 row)
168+
169+
SELECT local_blks_dirtied > 0 AS subxact_buffers_visible
170+
FROM pg_session_buffer_usage();
171+
subxact_buffers_visible
172+
-------------------------
173+
t
174+
(1 row)
175+
176+
DROP FUNCTION subxact_exc_func;
177+
DROP TABLE subxact_tab;
178+
-- Cursor (FOR loop) in aborted subtransaction; verify post-exception tracking
179+
CREATE TEMP TABLE cursor_tab (a int, b char(200));
180+
INSERT INTO cursor_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
181+
CREATE FUNCTION cursor_exc_func() RETURNS text AS $$
182+
DECLARE
183+
rec record;
184+
cnt int := 0;
185+
BEGIN
186+
BEGIN
187+
FOR rec IN SELECT * FROM cursor_tab LOOP
188+
cnt := cnt + 1;
189+
IF cnt = 250 THEN
190+
PERFORM 1 / 0;
191+
END IF;
192+
END LOOP;
193+
EXCEPTION WHEN division_by_zero THEN
194+
RETURN 'caught after ' || cnt || ' rows';
195+
END;
196+
RETURN 'not reached';
197+
END;
198+
$$ LANGUAGE plpgsql;
199+
SELECT pg_session_buffer_usage_reset();
200+
pg_session_buffer_usage_reset
201+
-------------------------------
202+
203+
(1 row)
204+
205+
SELECT cursor_exc_func();
206+
cursor_exc_func
207+
-----------------------
208+
caught after 250 rows
209+
(1 row)
210+
211+
SELECT local_blks_hit + local_blks_read > 0
212+
AS cursor_subxact_buffers_visible
213+
FROM pg_session_buffer_usage();
214+
cursor_subxact_buffers_visible
215+
--------------------------------
216+
t
217+
(1 row)
218+
219+
DROP FUNCTION cursor_exc_func;
220+
DROP TABLE cursor_tab;
221+
-- Trigger abort under EXPLAIN ANALYZE: verify that buffer activity from a
222+
-- trigger that throws an error is still properly propagated.
223+
CREATE TEMP TABLE trig_err_tab (a int);
224+
CREATE TEMP TABLE trig_work_tab (a int, b char(200));
225+
INSERT INTO trig_work_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
226+
-- Warm local buffers so trig_work_tab reads become hits
227+
SELECT count(*) FROM trig_work_tab;
228+
count
229+
-------
230+
500
231+
(1 row)
232+
233+
CREATE FUNCTION trig_err_func() RETURNS trigger AS $$
234+
BEGIN
235+
PERFORM count(*) FROM trig_work_tab;
236+
RAISE EXCEPTION 'trigger error';
237+
RETURN NEW;
238+
END;
239+
$$ LANGUAGE plpgsql;
240+
CREATE TRIGGER trig_err BEFORE INSERT ON trig_err_tab
241+
FOR EACH ROW EXECUTE FUNCTION trig_err_func();
242+
-- Measure how many local buffer hits a scan of trig_work_tab produces
243+
SELECT pg_session_buffer_usage_reset();
244+
pg_session_buffer_usage_reset
245+
-------------------------------
246+
247+
(1 row)
248+
249+
SELECT count(*) FROM trig_work_tab;
250+
count
251+
-------
252+
500
253+
(1 row)
254+
255+
CREATE TEMP TABLE trig_serial_result AS
256+
SELECT local_blks_hit AS serial_hits FROM pg_session_buffer_usage();
257+
-- Now trigger the same scan via a trigger that errors
258+
SELECT pg_session_buffer_usage_reset();
259+
pg_session_buffer_usage_reset
260+
-------------------------------
261+
262+
(1 row)
263+
264+
EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
265+
INSERT INTO trig_err_tab VALUES (1);
266+
ERROR: trigger error
267+
CONTEXT: PL/pgSQL function trig_err_func() line 4 at RAISE
268+
-- The trigger scanned trig_work_tab but errored before InstrStopTrigger ran.
269+
-- InstrStopFinalize in the PG_CATCH ensures buffer data is still propagated.
270+
SELECT local_blks_hit >= s.serial_hits / 2
271+
AS trigger_abort_buffers_propagated
272+
FROM pg_session_buffer_usage(), trig_serial_result s;
273+
trigger_abort_buffers_propagated
274+
----------------------------------
275+
t
276+
(1 row)
277+
278+
DROP TABLE trig_err_tab, trig_work_tab, trig_serial_result;
279+
DROP FUNCTION trig_err_func;
280+
-- Parallel worker abort: worker buffer activity is currently NOT propagated on abort.
281+
--
282+
-- When a parallel worker aborts, InstrEndParallelQuery and
283+
-- ExecParallelReportInstrumentation never run, so the worker's buffer
284+
-- activity is never written to shared memory, despite the information having been
285+
-- captured by the res owner release instrumentation handling.
286+
CREATE TABLE par_abort_tab (a int, b char(200));
287+
INSERT INTO par_abort_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
288+
-- Warm shared buffers so all reads become hits
289+
SELECT count(*) FROM par_abort_tab;
290+
count
291+
-------
292+
5000
293+
(1 row)
294+
295+
-- Measure serial scan delta as a reference (leader reads all blocks)
296+
SET max_parallel_workers_per_gather = 0;
297+
SELECT pg_session_buffer_usage_reset();
298+
pg_session_buffer_usage_reset
299+
-------------------------------
300+
301+
(1 row)
302+
303+
SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
304+
ERROR: invalid input syntax for type smallint: "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"
305+
CREATE TABLE par_abort_serial_result AS
306+
SELECT shared_blks_hit AS serial_delta FROM pg_session_buffer_usage();
307+
-- Now force parallel with leader NOT participating in scanning
308+
SET parallel_setup_cost = 0;
309+
SET parallel_tuple_cost = 0;
310+
SET min_parallel_table_scan_size = 0;
311+
SET max_parallel_workers_per_gather = 2;
312+
SET parallel_leader_participation = off;
313+
SET debug_parallel_query = on; -- Ensure we get CONTEXT line consistently
314+
SELECT pg_session_buffer_usage_reset();
315+
pg_session_buffer_usage_reset
316+
-------------------------------
317+
318+
(1 row)
319+
320+
SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
321+
ERROR: invalid input syntax for type smallint: "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"
322+
CONTEXT: parallel worker
323+
RESET debug_parallel_query;
324+
-- Workers scanned the table but aborted before reporting stats back.
325+
-- The leader's delta should be much less than a serial scan, documenting
326+
-- that worker buffer activity is lost on abort.
327+
SELECT shared_blks_hit < s.serial_delta / 2
328+
AS worker_abort_buffers_not_propagated
329+
FROM pg_session_buffer_usage(), par_abort_serial_result s;
330+
worker_abort_buffers_not_propagated
331+
-------------------------------------
332+
t
333+
(1 row)
334+
335+
RESET parallel_setup_cost;
336+
RESET parallel_tuple_cost;
337+
RESET min_parallel_table_scan_size;
338+
RESET max_parallel_workers_per_gather;
339+
RESET parallel_leader_participation;
340+
DROP TABLE par_abort_tab, par_abort_serial_result;
341+
-- Cleanup
342+
DROP EXTENSION pg_session_buffer_usage;

0 commit comments

Comments
 (0)