public inbox for [email protected]
help / color / mirror / Atom feedFrom: Lukas Fittl <[email protected]>
To: Andres Freund <[email protected]>
Cc: Heikki Linnakangas <[email protected]>
Cc: PostgreSQL Hackers <[email protected]>
Cc: Zsolt Parragi <[email protected]>
Cc: Tomas Vondra <[email protected]>
Cc: Peter Smith <[email protected]>
Subject: Re: Stack-based tracking of per-node WAL/buffer usage
Date: Mon, 6 Apr 2026 02:58:39 -0700
Message-ID: <CAP53Pkzec5L=PDvF+zrPei2kM1FZH6pD2aD=zFWXwzW8oKXJBg@mail.gmail.com> (raw)
In-Reply-To: <3xbje45m5knff52mye5dfnrjdnwv7it2bzmqac3jqe66fvop4a@xvhy6zx7n6sb>
References: <CAP53PkznofNg+ii363QQGoje30nhssuSz_hV5U4YANAt-Yr_Yg@mail.gmail.com>
<[email protected]>
<CAP53PkwCk7X_ryOak_3x6ek2f+4kCgGjWe8aVy39D59Q8y9wTg@mail.gmail.com>
<CAP53Pky2=31B1AS9vg=Ca9308_hb0H4g968cSKxiFgT0moJfYg@mail.gmail.com>
<CAP53PkybGzJTAo7V07ssUae5047pBY3jc_F07tGY13cNhqe+AQ@mail.gmail.com>
<57biou6l65r7gr4nunoe6lignz2x6m3w45gihoypaez4pc46di@txj3bakhj66l>
<CAP53PkxDupm5U6TV0LF_YWHQ2wfcSiLsgnDBcO6b5AchLJhp=A@mail.gmail.com>
<mtjyijvuv7xavvcdy3rosg43ycy3t5sluioxkef46se25ajtxp@e3e2xvesqhzu>
<CAP53Pky4zHCueAyPkWE-cH6SqE_m+Kppmy=zE5K36X3HvCFZLw@mail.gmail.com>
<pgvy7lsoa5jldwgyay2g757xivzbmgyan547wealc7cwtduvra@dysyw6dtqdgs>
<3xbje45m5knff52mye5dfnrjdnwv7it2bzmqac3jqe66fvop4a@xvhy6zx7n6sb>
On Sun, Apr 5, 2026 at 4:12 PM Andres Freund <[email protected]> wrote:
>
> Hi,
>
> On 2026-04-05 17:02:28 -0400, Andres Freund wrote:
> > With that I pushed 0001.
>
> For 0002 I:
> - fixed a few comments still refering to node in the generic Instr* functions
> - added comment about the async_mode buglet to the commit message
> - added an async_mode argument to InstrInitNode(), as its callsite already
> needed to be touched, and it felt wrong that InstrAllocNode() could do
> things that were not possible with InstrInitNode()
> - Deduplicated the code between InstrStop() and InstrStotNode() by introducing
> InstrStopCommon()
>
> After those (and some testing) I pushed this.
>
Thanks for pushing these two! And appreciate the refinements, they
make sense to me.
Attached v15. Quick summary:
0001 converts direct users of pgBufferUsage/pgWalUsage to the new
general purpose Instrumentation just pushed.
0002 introduces the macros needed for the stack-based instrumentation,
same as before.
0003 adds additional test coverage for buffer usage, same as before.
0004 is new, and adds queryDesc->totaltime_options for extensions to
request a certain level of totaltime measurement (this solves the
problem Andres noted in a review comment)
0005 is the stack-based instrumentation commit, now smaller and more
digestible, with the same performance benefits.
-- if we get up to here, we get the main benefit --
0006 is the parallel instrumentation cleanup. I don't think we need
this right now unless the EXPLAIN (IO) work changes course.
0007 is the same ExecProcNodeInstr change as before (this one we could
simplify by simply moving the function, getting about half the
possible speedup)
0008 is the table-specific buffer measurement for index scans (for
current master)
0009 is the test module for top level instrumentation data.
I've also attached an alternate for 0008, that works on top of the
index prefetch work (v23) - the change actually gets smaller because
heap fetches are better encapsulated then.
Thanks,
Lukas
--
Lukas Fittl
Attachments:
[application/octet-stream] nocfbot-0008-post-index-prefetch-Index-scans-Show-table-buffer-accesses-separately.patch (20.4K, 2-nocfbot-0008-post-index-prefetch-Index-scans-Show-table-buffer-accesses-separately.patch)
download | inline diff:
From ecba8752d060f19f43ed3297af5b8314e26a7767 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sat, 7 Mar 2026 11:46:19 -0800
Subject: [PATCH v0 1/2] Index scans: Show table buffer accesses separately in
EXPLAIN ANALYZE
This sets up a separate instrumentation stack that is used whilst an
Index Scan or Index Only Scan does scanning on the table, for example due
to additional data being needed.
EXPLAIN ANALYZE will now show "Table Buffers" that represent such activity.
The activity is also included in regular "Buffers" together with index
activity and that of any child nodes.
Author: Lukas Fittl <[email protected]>
Suggested-by: Andres Freund <[email protected]>
Reviewed-by: Zsolt Parragi <[email protected]> (in an earlier version)
Reviewed-by: Tomas Vondra <[email protected]> (in an earlier version)
Discussion: https://www.postgresql.org/message-id/flat/CAP53PkxrmpECzVFpeeEEHDGe6u625s%2BYkmVv5-gw3L_NDSfbiA%40mail.gmail.com#cb583a08e8e096aa1f093bb178906173
---
doc/src/sgml/perform.sgml | 13 ++++--
doc/src/sgml/ref/explain.sgml | 1 +
src/backend/access/heap/heapam_indexscan.c | 16 ++++++--
src/backend/commands/explain.c | 48 ++++++++++++++++++----
src/backend/executor/execProcnode.c | 46 +++++++++++++++++++++
src/backend/executor/nodeBitmapIndexscan.c | 2 +-
src/backend/executor/nodeIndexonlyscan.c | 24 ++++++++++-
src/backend/executor/nodeIndexscan.c | 24 ++++++++++-
src/include/executor/instrument_node.h | 5 +++
9 files changed, 162 insertions(+), 17 deletions(-)
diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml
index 604e8578a8d..d28f4f22535 100644
--- a/doc/src/sgml/perform.sgml
+++ b/doc/src/sgml/perform.sgml
@@ -734,6 +734,7 @@ WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
-> Index Scan using tenk2_unique2 on tenk2 t2 (cost=0.29..7.90 rows=1 width=244) (actual time=0.003..0.003 rows=1.00 loops=10)
Index Cond: (unique2 = t1.unique2)
Index Searches: 10
+ Table Buffers: shared hit=10
Buffers: shared hit=24 read=6
Planning:
Buffers: shared hit=15 dirtied=9
@@ -1005,7 +1006,8 @@ EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
Index Cond: (f1 @> '((0.5,2))'::polygon)
Rows Removed by Index Recheck: 1
Index Searches: 1
- Buffers: shared hit=1
+ Table Buffers: shared hit=1
+ Buffers: shared hit=2
Planning Time: 0.039 ms
Execution Time: 0.098 ms
</screen>
@@ -1014,7 +1016,9 @@ EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
then rejected by a recheck of the index condition. This happens because a
GiST index is <quote>lossy</quote> for polygon containment tests: it actually
returns the rows with polygons that overlap the target, and then we have
- to do the exact containment test on those rows.
+ to do the exact containment test on those rows. The <literal>Table Buffers</literal>
+ counts indicate how many operations were performed on the table instead of
+ the index. This number is included in the <literal>Buffers</literal> counts.
</para>
<para>
@@ -1203,13 +1207,14 @@ EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE unique1 < 100 AND unique2 > 9000
QUERY PLAN
-------------------------------------------------------------------&zwsp;------------------------------------------------------------
Limit (cost=0.29..14.33 rows=2 width=244) (actual time=0.051..0.071 rows=2.00 loops=1)
- Buffers: shared hit=16
+ Buffers: shared hit=14
-> Index Scan using tenk1_unique2 on tenk1 (cost=0.29..70.50 rows=10 width=244) (actual time=0.051..0.070 rows=2.00 loops=1)
Index Cond: (unique2 > 9000)
Filter: (unique1 < 100)
Rows Removed by Filter: 287
Index Searches: 1
- Buffers: shared hit=16
+ Table Buffers: shared hit=11
+ Buffers: shared hit=14
Planning Time: 0.077 ms
Execution Time: 0.086 ms
</screen>
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 5b8b521802e..71070736acb 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -509,6 +509,7 @@ EXPLAIN ANALYZE EXECUTE query(100, 200);
-> Index Scan using test_pkey on test (cost=0.29..10.27 rows=99 width=8) (actual time=0.009..0.025 rows=99.00 loops=1)
Index Cond: ((id > 100) AND (id < 200))
Index Searches: 1
+ Table Buffers: shared hit=1
Buffers: shared hit=4
Planning Time: 0.244 ms
Execution Time: 0.073 ms
diff --git a/src/backend/access/heap/heapam_indexscan.c b/src/backend/access/heap/heapam_indexscan.c
index fd70ad5bc2c..702419cbabf 100644
--- a/src/backend/access/heap/heapam_indexscan.c
+++ b/src/backend/access/heap/heapam_indexscan.c
@@ -572,11 +572,14 @@ heapam_index_fetch_tuple(Relation rel,
static pg_attribute_always_inline bool
heapam_index_fetch_heap_item(IndexScanDesc scan, IndexFetchHeapData *hscan,
TupleTableSlot *slot, bool *heap_continue,
- bool amgetbatch)
+ bool amgetbatch, Instrumentation *table_instr)
{
bool all_dead = false;
bool found;
+ if (table_instr)
+ InstrPushStack(table_instr);
+
found = heapam_index_fetch_tuple(scan->heapRelation, hscan,
&scan->xs_heaptid,
scan->xs_snapshot, slot,
@@ -607,6 +610,9 @@ heapam_index_fetch_heap_item(IndexScanDesc scan, IndexFetchHeapData *hscan,
}
}
+ if (table_instr)
+ InstrPopStack(table_instr);
+
return found;
}
@@ -1390,6 +1396,10 @@ heapam_index_getnext_slot(IndexScanDesc scan, ScanDirection direction,
BlockNumber last_visited_block = InvalidBlockNumber;
uint8 n_visited_pages = 0;
ItemPointer tid = NULL;
+ Instrumentation *table_instr = NULL;
+
+ if (scan->instrument && scan->instrument->table_instr.need_stack)
+ table_instr = &scan->instrument->table_instr;
for (;;)
{
@@ -1434,7 +1444,7 @@ heapam_index_getnext_slot(IndexScanDesc scan, ScanDirection direction,
scan->instrument->ntabletuplefetches++;
if (!heapam_index_fetch_heap_item(scan, hscan, slot,
- heap_continue, amgetbatch))
+ heap_continue, amgetbatch, table_instr))
{
/*
* No visible tuple. If caller set a visited-pages limit
@@ -1494,7 +1504,7 @@ heapam_index_getnext_slot(IndexScanDesc scan, ScanDirection direction,
* next TID from the index.
*/
if (heapam_index_fetch_heap_item(scan, hscan, slot, heap_continue,
- amgetbatch))
+ amgetbatch, table_instr))
return true;
}
}
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index ae3258b3f5c..647be5d1286 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -144,7 +144,7 @@ static void show_instrumentation_count(const char *qlabel, int which,
static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
static const char *explain_get_index_name(Oid indexId);
static bool peek_buffer_usage(ExplainState *es, const BufferUsage *usage);
-static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
+static void show_buffer_usage(ExplainState *es, const BufferUsage *usage, const char *title);
static void show_wal_usage(ExplainState *es, const WalUsage *usage);
static void show_memory_counters(ExplainState *es,
const MemoryContextCounters *mem_counters);
@@ -611,7 +611,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
}
if (bufusage)
- show_buffer_usage(es, bufusage);
+ show_buffer_usage(es, bufusage, NULL);
if (mem_counters)
show_memory_counters(es, mem_counters);
@@ -1028,7 +1028,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
if (es->buffers && peek_buffer_usage(es, &metrics->instr.bufusage))
{
es->indent++;
- show_buffer_usage(es, &metrics->instr.bufusage);
+ show_buffer_usage(es, &metrics->instr.bufusage, NULL);
es->indent--;
}
}
@@ -1042,7 +1042,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
BYTES_TO_KILOBYTES(metrics->bytesSent), es);
ExplainPropertyText("Format", format, es);
if (es->buffers)
- show_buffer_usage(es, &metrics->instr.bufusage);
+ show_buffer_usage(es, &metrics->instr.bufusage, NULL);
}
ExplainCloseGroup("Serialization", "Serialization", true, es);
@@ -2287,7 +2287,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
/* Show buffer/WAL usage */
if (es->buffers && planstate->instrument)
- show_buffer_usage(es, &planstate->instrument->instr.bufusage);
+ show_buffer_usage(es, &planstate->instrument->instr.bufusage, NULL);
if (es->wal && planstate->instrument)
show_wal_usage(es, &planstate->instrument->instr.walusage);
@@ -2306,7 +2306,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
ExplainOpenWorker(n, es);
if (es->buffers)
- show_buffer_usage(es, &instrument->instr.bufusage);
+ show_buffer_usage(es, &instrument->instr.bufusage, NULL);
if (es->wal)
show_wal_usage(es, &instrument->instr.walusage);
ExplainCloseWorker(n, es);
@@ -3862,6 +3862,7 @@ show_indexscan_info(PlanState *planstate, ExplainState *es)
{
Plan *plan = planstate->plan;
SharedIndexScanInstrumentation *SharedInfo = NULL;
+ Instrumentation *table_instr = NULL;
uint64 nsearches = 0,
ntabletuplefetches = 0;
@@ -3877,6 +3878,7 @@ show_indexscan_info(PlanState *planstate, ExplainState *es)
nsearches = indexstate->iss_Instrument->nsearches;
SharedInfo = indexstate->iss_SharedInfo;
+ table_instr = &indexstate->iss_Instrument->table_instr;
break;
}
case T_IndexOnlyScan:
@@ -3886,6 +3888,7 @@ show_indexscan_info(PlanState *planstate, ExplainState *es)
nsearches = indexstate->ioss_Instrument->nsearches;
ntabletuplefetches = indexstate->ioss_Instrument->ntabletuplefetches;
SharedInfo = indexstate->ioss_SharedInfo;
+ table_instr = &indexstate->ioss_Instrument->table_instr;
break;
}
case T_BitmapIndexScan:
@@ -3894,6 +3897,7 @@ show_indexscan_info(PlanState *planstate, ExplainState *es)
nsearches = indexstate->biss_Instrument->nsearches;
SharedInfo = indexstate->biss_SharedInfo;
+ table_instr = &indexstate->biss_Instrument->table_instr;
break;
}
default:
@@ -3916,6 +3920,9 @@ show_indexscan_info(PlanState *planstate, ExplainState *es)
ExplainPropertyUInteger("Heap Fetches", NULL, ntabletuplefetches, es);
ExplainPropertyUInteger("Index Searches", NULL, nsearches, es);
+
+ if (es->buffers && table_instr)
+ show_buffer_usage(es, &table_instr->bufusage, "Table");
}
/*
@@ -4112,7 +4119,7 @@ peek_buffer_usage(ExplainState *es, const BufferUsage *usage)
* Show buffer usage details. This better be sync with peek_buffer_usage.
*/
static void
-show_buffer_usage(ExplainState *es, const BufferUsage *usage)
+show_buffer_usage(ExplainState *es, const BufferUsage *usage, const char *title)
{
if (es->format == EXPLAIN_FORMAT_TEXT)
{
@@ -4137,6 +4144,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
if (has_shared || has_local || has_temp)
{
ExplainIndentText(es);
+ if (title)
+ appendStringInfo(es->str, "%s ", title);
appendStringInfoString(es->str, "Buffers:");
if (has_shared)
@@ -4192,6 +4201,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
if (has_shared_timing || has_local_timing || has_temp_timing)
{
ExplainIndentText(es);
+ if (title)
+ appendStringInfo(es->str, "%s ", title);
appendStringInfoString(es->str, "I/O Timings:");
if (has_shared_timing)
@@ -4233,6 +4244,14 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
else
{
+ char *buffers_title = NULL;
+
+ if (title)
+ {
+ buffers_title = psprintf("%s Buffers", title);
+ ExplainOpenGroup(buffers_title, buffers_title, true, es);
+ }
+
ExplainPropertyInteger("Shared Hit Blocks", NULL,
usage->shared_blks_hit, es);
ExplainPropertyInteger("Shared Read Blocks", NULL,
@@ -4253,8 +4272,20 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
usage->temp_blks_read, es);
ExplainPropertyInteger("Temp Written Blocks", NULL,
usage->temp_blks_written, es);
+
+ if (buffers_title)
+ ExplainCloseGroup(buffers_title, buffers_title, true, es);
+
if (track_io_timing)
{
+ char *timings_title = NULL;
+
+ if (title)
+ {
+ timings_title = psprintf("%s I/O Timings", title);
+ ExplainOpenGroup(timings_title, timings_title, true, es);
+ }
+
ExplainPropertyFloat("Shared I/O Read Time", "ms",
INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time),
3, es);
@@ -4273,6 +4304,9 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
ExplainPropertyFloat("Temp I/O Write Time", "ms",
INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time),
3, es);
+
+ if (timings_title)
+ ExplainCloseGroup(timings_title, timings_title, true, es);
}
}
}
diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c
index ac400670fea..28f1f666a3b 100644
--- a/src/backend/executor/execProcnode.c
+++ b/src/backend/executor/execProcnode.c
@@ -847,6 +847,20 @@ ExecFinalizeNodeInstrumentation_walker(PlanState *node, void *context)
planstate_tree_walker(node, ExecFinalizeNodeInstrumentation_walker,
&node->instrument->instr);
+ /* IndexScan/IndexOnlyScan have a separate entry to track table access */
+ if (IsA(node, IndexScanState))
+ {
+ IndexScanState *iss = castNode(IndexScanState, node);
+
+ InstrFinalizeChild(&iss->iss_Instrument->table_instr, &node->instrument->instr);
+ }
+ else if (IsA(node, IndexOnlyScanState))
+ {
+ IndexOnlyScanState *ioss = castNode(IndexOnlyScanState, node);
+
+ InstrFinalizeChild(&ioss->ioss_Instrument->table_instr, &node->instrument->instr);
+ }
+
InstrFinalizeChild(&node->instrument->instr, parent);
return false;
@@ -892,6 +906,38 @@ ExecFinalizeWorkerInstrumentation_walker(PlanState *node, void *context)
num_workers = node->worker_instrument->num_workers;
+ /*
+ * Fold per-worker IndexScan/IndexOnlyScan table buffer stats into the
+ * per-worker node stats, matching what ExecFinalizeNodeInstrumentation
+ * does for the leader.
+ */
+ if (IsA(node, IndexScanState))
+ {
+ IndexScanState *iss = castNode(IndexScanState, node);
+
+ if (iss->iss_SharedInfo)
+ {
+ int nworkers = Min(num_workers, iss->iss_SharedInfo->num_workers);
+
+ for (int n = 0; n < nworkers; n++)
+ InstrAccumStack(&node->worker_instrument->instrument[n].instr,
+ &iss->iss_SharedInfo->winstrument[n].table_instr);
+ }
+ }
+ else if (IsA(node, IndexOnlyScanState))
+ {
+ IndexOnlyScanState *ioss = castNode(IndexOnlyScanState, node);
+
+ if (ioss->ioss_SharedInfo)
+ {
+ int nworkers = Min(num_workers, ioss->ioss_SharedInfo->num_workers);
+
+ for (int n = 0; n < nworkers; n++)
+ InstrAccumStack(&node->worker_instrument->instrument[n].instr,
+ &ioss->ioss_SharedInfo->winstrument[n].table_instr);
+ }
+ }
+
/* Accumulate this node's per-worker stats to parent's per-worker stats */
if (parent && parent->worker_instrument)
{
diff --git a/src/backend/executor/nodeBitmapIndexscan.c b/src/backend/executor/nodeBitmapIndexscan.c
index a9a3d2fb149..ff802b86446 100644
--- a/src/backend/executor/nodeBitmapIndexscan.c
+++ b/src/backend/executor/nodeBitmapIndexscan.c
@@ -277,7 +277,7 @@ ExecInitBitmapIndexScan(BitmapIndexScan *node, EState *estate, int eflags)
/* Set up instrumentation of bitmap index scans if requested */
if (estate->es_instrument)
- indexstate->biss_Instrument = palloc0_object(IndexScanInstrumentation);
+ indexstate->biss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
diff --git a/src/backend/executor/nodeIndexonlyscan.c b/src/backend/executor/nodeIndexonlyscan.c
index b6b9dbd1075..9ff77a25a95 100644
--- a/src/backend/executor/nodeIndexonlyscan.c
+++ b/src/backend/executor/nodeIndexonlyscan.c
@@ -347,6 +347,7 @@ ExecEndIndexOnlyScan(IndexOnlyScanState *node)
*/
winstrument->nsearches += node->ioss_Instrument->nsearches;
winstrument->ntabletuplefetches += node->ioss_Instrument->ntabletuplefetches;
+ InstrAccumStack(&winstrument->table_instr, &node->ioss_Instrument->table_instr);
}
/*
@@ -521,7 +522,21 @@ ExecInitIndexOnlyScan(IndexOnlyScan *node, EState *estate, int eflags)
/* Set up instrumentation of index-only scans if requested */
if (estate->es_instrument)
- indexstate->ioss_Instrument = palloc0_object(IndexScanInstrumentation);
+ {
+ indexstate->ioss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
+
+ /*
+ * Track table and index access separately. We intentionally don't
+ * collect timing (even if enabled), since we don't need it, and
+ * IndexOnlyNext calls InstrPushStack / InstrPopStack (instead of the
+ * full InstrNode*) to reduce overhead.
+ */
+ if ((estate->es_instrument & INSTRUMENT_BUFFERS) != 0)
+ {
+ InstrInitOptions(&indexstate->ioss_Instrument->table_instr, INSTRUMENT_BUFFERS);
+ InstrQueryRememberChild(estate->es_query_instr, &indexstate->ioss_Instrument->table_instr);
+ }
+ }
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
@@ -811,4 +826,11 @@ ExecIndexOnlyScanRetrieveInstrumentation(IndexOnlyScanState *node)
SharedInfo->num_workers * sizeof(IndexScanInstrumentation);
node->ioss_SharedInfo = palloc(size);
memcpy(node->ioss_SharedInfo, SharedInfo, size);
+
+ /* Aggregate workers' table buffer/WAL usage into leader's entry */
+ for (int i = 0; i < node->ioss_SharedInfo->num_workers; i++)
+ {
+ InstrAccumStack(&node->ioss_Instrument->table_instr,
+ &node->ioss_SharedInfo->winstrument[i].table_instr);
+ }
}
diff --git a/src/backend/executor/nodeIndexscan.c b/src/backend/executor/nodeIndexscan.c
index 2ac854da468..d3ae4d016c4 100644
--- a/src/backend/executor/nodeIndexscan.c
+++ b/src/backend/executor/nodeIndexscan.c
@@ -821,6 +821,7 @@ ExecEndIndexScan(IndexScanState *node)
*/
winstrument->nsearches += node->iss_Instrument->nsearches;
Assert(node->iss_Instrument->ntabletuplefetches == 0);
+ InstrAccumStack(&winstrument->table_instr, &node->iss_Instrument->table_instr);
}
/*
@@ -983,7 +984,21 @@ ExecInitIndexScan(IndexScan *node, EState *estate, int eflags)
/* Set up instrumentation of index scans if requested */
if (estate->es_instrument)
- indexstate->iss_Instrument = palloc0_object(IndexScanInstrumentation);
+ {
+ indexstate->iss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
+
+ /*
+ * Track table and index access separately. We intentionally don't
+ * collect timing (even if enabled), since we don't need it, and
+ * IndexNext / IndexNextWithReorder call InstrPushStack /
+ * InstrPopStack (instead of the full InstrNode*) to reduce overhead.
+ */
+ if ((estate->es_instrument & INSTRUMENT_BUFFERS) != 0)
+ {
+ InstrInitOptions(&indexstate->iss_Instrument->table_instr, INSTRUMENT_BUFFERS);
+ InstrQueryRememberChild(estate->es_query_instr, &indexstate->iss_Instrument->table_instr);
+ }
+ }
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
@@ -1839,4 +1854,11 @@ ExecIndexScanRetrieveInstrumentation(IndexScanState *node)
SharedInfo->num_workers * sizeof(IndexScanInstrumentation);
node->iss_SharedInfo = palloc(size);
memcpy(node->iss_SharedInfo, SharedInfo, size);
+
+ /* Aggregate workers' table buffer/WAL usage into leader's entry */
+ for (int i = 0; i < node->iss_SharedInfo->num_workers; i++)
+ {
+ InstrAccumStack(&node->iss_Instrument->table_instr,
+ &node->iss_SharedInfo->winstrument[i].table_instr);
+ }
}
diff --git a/src/include/executor/instrument_node.h b/src/include/executor/instrument_node.h
index 78f810aabaf..bf0c4416dae 100644
--- a/src/include/executor/instrument_node.h
+++ b/src/include/executor/instrument_node.h
@@ -18,6 +18,8 @@
#ifndef INSTRUMENT_NODE_H
#define INSTRUMENT_NODE_H
+#include "executor/instrument.h"
+
/* ---------------------
* Instrumentation information for aggregate function execution
@@ -51,6 +53,9 @@ typedef struct IndexScanInstrumentation
/* Table tuples fetched count (incremented during index-only scans) */
uint64 ntabletuplefetches;
+
+ /* Instrumentation utilized for tracking buffer usage during table access */
+ Instrumentation table_instr;
} IndexScanInstrumentation;
/*
--
2.47.1
[application/octet-stream] v15-0003-instrumentation-Add-additional-regression-tests-.patch (22.5K, 3-v15-0003-instrumentation-Add-additional-regression-tests-.patch)
download | inline diff:
From 97681481fb96a5907830d405ed5c2564baddb872 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sun, 5 Apr 2026 03:48:32 -0700
Subject: [PATCH v15 3/9] instrumentation: Add additional regression tests
covering buffer usage
This adds regression tests that cover some of the expected behaviour
around the buffer statistics reported in EXPLAIN ANALYZE, specifically
how they behave in parallel query, nested function calls and abort
situations.
Testing this is challenging because there can be different sources of
buffer activity, so we rely on temporary tables where we can to prove
that activity was captured and not lost. This supports a future commit
that will rework some of the instrumentation logic that could cause
areas covered by these tests to fail.
Author: Lukas Fittl <[email protected]>
Reviewed-by:
Discussion:
---
.../pg_stat_statements/expected/utility.out | 70 +++++++
contrib/pg_stat_statements/expected/wal.out | 48 +++++
contrib/pg_stat_statements/sql/utility.sql | 56 ++++++
contrib/pg_stat_statements/sql/wal.sql | 33 +++
src/test/regress/expected/explain.out | 188 ++++++++++++++++++
src/test/regress/sql/explain.sql | 188 ++++++++++++++++++
6 files changed, 583 insertions(+)
diff --git a/contrib/pg_stat_statements/expected/utility.out b/contrib/pg_stat_statements/expected/utility.out
index e4d6564ea5b..cba487f6be5 100644
--- a/contrib/pg_stat_statements/expected/utility.out
+++ b/contrib/pg_stat_statements/expected/utility.out
@@ -289,6 +289,76 @@ SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C";
1 | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t
(3 rows)
+-- Buffer stats should flow through EXPLAIN ANALYZE
+CREATE TEMP TABLE flow_through_test (a int, b char(200));
+INSERT INTO flow_through_test SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+CREATE FUNCTION run_explain_buffers_test() RETURNS void AS $$
+DECLARE
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM flow_through_test';
+END;
+$$ LANGUAGE plpgsql;
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+ t
+---
+ t
+(1 row)
+
+SELECT run_explain_buffers_test();
+ run_explain_buffers_test
+--------------------------
+
+(1 row)
+
+-- EXPLAIN entries should have non-zero buffer stats
+SELECT query, local_blks_hit + local_blks_read > 0 as has_buffer_stats
+FROM pg_stat_statements
+WHERE query LIKE 'SELECT run_explain_buffers_test%'
+ORDER BY query COLLATE "C";
+ query | has_buffer_stats
+-----------------------------------+------------------
+ SELECT run_explain_buffers_test() | t
+(1 row)
+
+DROP FUNCTION run_explain_buffers_test;
+DROP TABLE flow_through_test;
+-- Validate buffer/WAL counting during abort
+SET pg_stat_statements.track = 'all';
+CREATE TEMP TABLE pgss_call_tab (a int, b char(20));
+CREATE TEMP TABLE pgss_call_tab2 (a int, b char(20));
+INSERT INTO pgss_call_tab VALUES (0, 'zzz');
+CREATE PROCEDURE pgss_call_rollback_proc() AS $$
+DECLARE
+ v int;
+BEGIN
+ EXPLAIN ANALYZE WITH ins AS (INSERT INTO pgss_call_tab2 SELECT * FROM pgss_call_tab RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+END;
+$$ LANGUAGE plpgsql;
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+ t
+---
+ t
+(1 row)
+
+CALL pgss_call_rollback_proc();
+SELECT query, calls,
+local_blks_hit + local_blks_read > 0 as local_hitread,
+wal_bytes > 0 as wal_bytes_generated,
+wal_records > 0 as wal_records_generated
+FROM pg_stat_statements
+WHERE query LIKE '%pgss_call_rollback_proc%'
+ORDER BY query COLLATE "C";
+ query | calls | local_hitread | wal_bytes_generated | wal_records_generated
+--------------------------------+-------+---------------+---------------------+-----------------------
+ CALL pgss_call_rollback_proc() | 1 | t | t | t
+(1 row)
+
+DROP TABLE pgss_call_tab2;
+DROP TABLE pgss_call_tab;
+DROP PROCEDURE pgss_call_rollback_proc;
+SET pg_stat_statements.track = 'top';
-- CALL
CREATE OR REPLACE PROCEDURE sum_one(i int) AS $$
DECLARE
diff --git a/contrib/pg_stat_statements/expected/wal.out b/contrib/pg_stat_statements/expected/wal.out
index 977e382d848..611213daef6 100644
--- a/contrib/pg_stat_statements/expected/wal.out
+++ b/contrib/pg_stat_statements/expected/wal.out
@@ -28,3 +28,51 @@ SELECT pg_stat_statements_reset() IS NOT NULL AS t;
t
(1 row)
+--
+-- Validate buffer/WAL counting with caught exception in PL/pgSQL
+--
+CREATE TEMP TABLE pgss_error_tab (a int, b char(20));
+INSERT INTO pgss_error_tab VALUES (0, 'zzz');
+CREATE FUNCTION pgss_error_func() RETURNS void AS $$
+DECLARE
+ v int;
+BEGIN
+ WITH ins AS (INSERT INTO pgss_error_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+ NULL;
+END;
+$$ LANGUAGE plpgsql;
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+ t
+---
+ t
+(1 row)
+
+SELECT pgss_error_func();
+ pgss_error_func
+-----------------
+
+(1 row)
+
+-- Buffer/WAL usage from the wCTE INSERT should survive the exception
+SELECT query, calls,
+local_blks_hit + local_blks_read > 0 as local_hitread,
+wal_bytes > 0 as wal_bytes_generated,
+wal_records > 0 as wal_records_generated
+FROM pg_stat_statements
+WHERE query LIKE '%pgss_error_func%'
+ORDER BY query COLLATE "C";
+ query | calls | local_hitread | wal_bytes_generated | wal_records_generated
+--------------------------+-------+---------------+---------------------+-----------------------
+ SELECT pgss_error_func() | 1 | t | t | t
+(1 row)
+
+DROP TABLE pgss_error_tab;
+DROP FUNCTION pgss_error_func;
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+ t
+---
+ t
+(1 row)
+
diff --git a/contrib/pg_stat_statements/sql/utility.sql b/contrib/pg_stat_statements/sql/utility.sql
index dd97203c210..7540e49c73c 100644
--- a/contrib/pg_stat_statements/sql/utility.sql
+++ b/contrib/pg_stat_statements/sql/utility.sql
@@ -152,6 +152,62 @@ EXPLAIN (costs off) SELECT a FROM generate_series(1,10) AS tab(a) WHERE a = 7;
SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C";
+-- Buffer stats should flow through EXPLAIN ANALYZE
+CREATE TEMP TABLE flow_through_test (a int, b char(200));
+INSERT INTO flow_through_test SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+
+CREATE FUNCTION run_explain_buffers_test() RETURNS void AS $$
+DECLARE
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM flow_through_test';
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+
+SELECT run_explain_buffers_test();
+
+-- EXPLAIN entries should have non-zero buffer stats
+SELECT query, local_blks_hit + local_blks_read > 0 as has_buffer_stats
+FROM pg_stat_statements
+WHERE query LIKE 'SELECT run_explain_buffers_test%'
+ORDER BY query COLLATE "C";
+
+DROP FUNCTION run_explain_buffers_test;
+DROP TABLE flow_through_test;
+
+-- Validate buffer/WAL counting during abort
+SET pg_stat_statements.track = 'all';
+CREATE TEMP TABLE pgss_call_tab (a int, b char(20));
+CREATE TEMP TABLE pgss_call_tab2 (a int, b char(20));
+INSERT INTO pgss_call_tab VALUES (0, 'zzz');
+
+CREATE PROCEDURE pgss_call_rollback_proc() AS $$
+DECLARE
+ v int;
+BEGIN
+ EXPLAIN ANALYZE WITH ins AS (INSERT INTO pgss_call_tab2 SELECT * FROM pgss_call_tab RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+CALL pgss_call_rollback_proc();
+
+SELECT query, calls,
+local_blks_hit + local_blks_read > 0 as local_hitread,
+wal_bytes > 0 as wal_bytes_generated,
+wal_records > 0 as wal_records_generated
+FROM pg_stat_statements
+WHERE query LIKE '%pgss_call_rollback_proc%'
+ORDER BY query COLLATE "C";
+
+DROP TABLE pgss_call_tab2;
+DROP TABLE pgss_call_tab;
+DROP PROCEDURE pgss_call_rollback_proc;
+SET pg_stat_statements.track = 'top';
+
-- CALL
CREATE OR REPLACE PROCEDURE sum_one(i int) AS $$
DECLARE
diff --git a/contrib/pg_stat_statements/sql/wal.sql b/contrib/pg_stat_statements/sql/wal.sql
index 1dc1552a81e..467e321b206 100644
--- a/contrib/pg_stat_statements/sql/wal.sql
+++ b/contrib/pg_stat_statements/sql/wal.sql
@@ -18,3 +18,36 @@ wal_records > 0 as wal_records_generated,
wal_records >= rows as wal_records_ge_rows
FROM pg_stat_statements ORDER BY query COLLATE "C";
SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+
+--
+-- Validate buffer/WAL counting with caught exception in PL/pgSQL
+--
+CREATE TEMP TABLE pgss_error_tab (a int, b char(20));
+INSERT INTO pgss_error_tab VALUES (0, 'zzz');
+
+CREATE FUNCTION pgss_error_func() RETURNS void AS $$
+DECLARE
+ v int;
+BEGIN
+ WITH ins AS (INSERT INTO pgss_error_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+ NULL;
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
+SELECT pgss_error_func();
+
+-- Buffer/WAL usage from the wCTE INSERT should survive the exception
+SELECT query, calls,
+local_blks_hit + local_blks_read > 0 as local_hitread,
+wal_bytes > 0 as wal_bytes_generated,
+wal_records > 0 as wal_records_generated
+FROM pg_stat_statements
+WHERE query LIKE '%pgss_error_func%'
+ORDER BY query COLLATE "C";
+
+DROP TABLE pgss_error_tab;
+DROP FUNCTION pgss_error_func;
+SELECT pg_stat_statements_reset() IS NOT NULL AS t;
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index 7c1f26b182c..5ff96491b0a 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -822,3 +822,191 @@ select explain_filter('explain (analyze,buffers off,costs off) select sum(n) ove
(9 rows)
reset work_mem;
+-- EXPLAIN (ANALYZE, BUFFERS) should report buffer usage from PL/pgSQL
+-- EXCEPTION blocks, even after subtransaction rollback.
+CREATE TEMP TABLE explain_exc_tab (a int, b char(20));
+INSERT INTO explain_exc_tab VALUES (0, 'zzz');
+CREATE FUNCTION explain_exc_func() RETURNS void AS $$
+DECLARE
+ v int;
+BEGIN
+ WITH ins AS (INSERT INTO explain_exc_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+ NULL;
+END;
+$$ LANGUAGE plpgsql;
+CREATE FUNCTION check_explain_exception_buffers() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ node json;
+ total_buffers int;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT explain_exc_func()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ total_buffers :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+ RETURN total_buffers > 0;
+END;
+$$ LANGUAGE plpgsql;
+SELECT check_explain_exception_buffers() AS exception_buffers_visible;
+ exception_buffers_visible
+---------------------------
+ t
+(1 row)
+
+-- Also test with nested EXPLAIN ANALYZE (two levels of instrumentation)
+CREATE FUNCTION check_explain_exception_buffers_nested() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ node json;
+ total_buffers int;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT check_explain_exception_buffers()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ total_buffers :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+ RETURN total_buffers > 0;
+END;
+$$ LANGUAGE plpgsql;
+SELECT check_explain_exception_buffers_nested() AS exception_buffers_nested_visible;
+ exception_buffers_nested_visible
+----------------------------------
+ t
+(1 row)
+
+DROP FUNCTION check_explain_exception_buffers_nested;
+DROP FUNCTION check_explain_exception_buffers;
+DROP FUNCTION explain_exc_func;
+DROP TABLE explain_exc_tab;
+-- Cursor instrumentation test.
+-- Verify that buffer usage is correctly tracked through cursor execution paths.
+-- Non-scrollable cursors exercise ExecShutdownNode after each ExecutorRun
+-- (EXEC_FLAG_BACKWARD is not set), while scrollable cursors only shut down
+-- nodes in ExecutorFinish. In both cases, buffer usage from the inner cursor
+-- scan should be correctly reported.
+CREATE TEMP TABLE cursor_buf_test AS SELECT * FROM tenk1;
+CREATE FUNCTION cursor_noscroll_scan() RETURNS bigint AS $$
+DECLARE
+ cur NO SCROLL CURSOR FOR SELECT * FROM cursor_buf_test;
+ rec RECORD;
+ cnt bigint := 0;
+BEGIN
+ OPEN cur;
+ LOOP
+ FETCH NEXT FROM cur INTO rec;
+ EXIT WHEN NOT FOUND;
+ cnt := cnt + 1;
+ END LOOP;
+ CLOSE cur;
+ RETURN cnt;
+END;
+$$ LANGUAGE plpgsql;
+CREATE FUNCTION cursor_scroll_scan() RETURNS bigint AS $$
+DECLARE
+ cur SCROLL CURSOR FOR SELECT * FROM cursor_buf_test;
+ rec RECORD;
+ cnt bigint := 0;
+BEGIN
+ OPEN cur;
+ LOOP
+ FETCH NEXT FROM cur INTO rec;
+ EXIT WHEN NOT FOUND;
+ cnt := cnt + 1;
+ END LOOP;
+ CLOSE cur;
+ RETURN cnt;
+END;
+$$ LANGUAGE plpgsql;
+CREATE FUNCTION check_cursor_explain_buffers() RETURNS TABLE(noscroll_ok boolean, scroll_ok boolean) AS $$
+DECLARE
+ plan_json json;
+ node json;
+ direct_buf int;
+ noscroll_buf int;
+ scroll_buf int;
+BEGIN
+ -- Direct scan: get leaf Seq Scan node buffers as baseline
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT * FROM cursor_buf_test' INTO plan_json;
+ node := plan_json->0->'Plan';
+ WHILE node->'Plans' IS NOT NULL LOOP
+ node := node->'Plans'->0;
+ END LOOP;
+ direct_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Non-scrollable cursor path: ExecShutdownNode runs after each ExecutorRun
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT cursor_noscroll_scan()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ noscroll_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Scrollable cursor path: ExecShutdownNode is skipped
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT cursor_scroll_scan()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ scroll_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Both cursor paths should report buffer counts about as high as
+ -- the direct scan (same data plus minor catalog overhead), and not
+ -- double-counted (< 2x the direct scan)
+ RETURN QUERY SELECT
+ (noscroll_buf >= direct_buf * 0.5 AND noscroll_buf < direct_buf * 2),
+ (scroll_buf >= direct_buf * 0.5 AND scroll_buf < direct_buf * 2);
+END;
+$$ LANGUAGE plpgsql;
+SELECT * FROM check_cursor_explain_buffers();
+ noscroll_ok | scroll_ok
+-------------+-----------
+ t | t
+(1 row)
+
+DROP FUNCTION check_cursor_explain_buffers;
+DROP FUNCTION cursor_noscroll_scan;
+DROP FUNCTION cursor_scroll_scan;
+DROP TABLE cursor_buf_test;
+-- Test trigger instrumentation.
+CREATE TEMP TABLE trig_test_tab (a int);
+CREATE TEMP TABLE trig_work_tab (a int);
+INSERT INTO trig_work_tab VALUES (1);
+CREATE FUNCTION trig_test_func() RETURNS trigger AS $$
+BEGIN
+ PERFORM * FROM trig_work_tab;
+ RETURN NEW;
+END;
+$$ LANGUAGE plpgsql;
+CREATE TRIGGER trig_test_trig
+ BEFORE INSERT ON trig_test_tab
+ FOR EACH ROW EXECUTE FUNCTION trig_test_func();
+CREATE FUNCTION check_trigger_explain_buffers() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ trig json;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ INSERT INTO trig_test_tab VALUES (1)' INTO plan_json;
+ trig := plan_json->0->'Triggers'->0;
+ RETURN COALESCE((trig->>'Calls')::int, 0) > 0;
+END;
+$$ LANGUAGE plpgsql;
+SELECT check_trigger_explain_buffers() AS trigger_buffers_visible;
+ trigger_buffers_visible
+-------------------------
+ t
+(1 row)
+
+DROP FUNCTION check_trigger_explain_buffers;
+DROP TRIGGER trig_test_trig ON trig_test_tab;
+DROP FUNCTION trig_test_func;
+DROP TABLE trig_test_tab;
+DROP TABLE trig_work_tab;
diff --git a/src/test/regress/sql/explain.sql b/src/test/regress/sql/explain.sql
index ebdab42604b..9f0e8524497 100644
--- a/src/test/regress/sql/explain.sql
+++ b/src/test/regress/sql/explain.sql
@@ -188,3 +188,191 @@ select explain_filter('explain (analyze,buffers off,costs off) select sum(n) ove
-- Test tuplestore storage usage in Window aggregate (memory and disk case, final result is disk)
select explain_filter('explain (analyze,buffers off,costs off) select sum(n) over(partition by m) from (SELECT n < 3 as m, n from generate_series(1,2500) a(n))');
reset work_mem;
+
+-- EXPLAIN (ANALYZE, BUFFERS) should report buffer usage from PL/pgSQL
+-- EXCEPTION blocks, even after subtransaction rollback.
+CREATE TEMP TABLE explain_exc_tab (a int, b char(20));
+INSERT INTO explain_exc_tab VALUES (0, 'zzz');
+
+CREATE FUNCTION explain_exc_func() RETURNS void AS $$
+DECLARE
+ v int;
+BEGIN
+ WITH ins AS (INSERT INTO explain_exc_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 INTO v FROM ins;
+EXCEPTION WHEN division_by_zero THEN
+ NULL;
+END;
+$$ LANGUAGE plpgsql;
+
+CREATE FUNCTION check_explain_exception_buffers() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ node json;
+ total_buffers int;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT explain_exc_func()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ total_buffers :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+ RETURN total_buffers > 0;
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT check_explain_exception_buffers() AS exception_buffers_visible;
+
+-- Also test with nested EXPLAIN ANALYZE (two levels of instrumentation)
+CREATE FUNCTION check_explain_exception_buffers_nested() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ node json;
+ total_buffers int;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT check_explain_exception_buffers()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ total_buffers :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+ RETURN total_buffers > 0;
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT check_explain_exception_buffers_nested() AS exception_buffers_nested_visible;
+
+DROP FUNCTION check_explain_exception_buffers_nested;
+DROP FUNCTION check_explain_exception_buffers;
+DROP FUNCTION explain_exc_func;
+DROP TABLE explain_exc_tab;
+
+-- Cursor instrumentation test.
+-- Verify that buffer usage is correctly tracked through cursor execution paths.
+-- Non-scrollable cursors exercise ExecShutdownNode after each ExecutorRun
+-- (EXEC_FLAG_BACKWARD is not set), while scrollable cursors only shut down
+-- nodes in ExecutorFinish. In both cases, buffer usage from the inner cursor
+-- scan should be correctly reported.
+
+CREATE TEMP TABLE cursor_buf_test AS SELECT * FROM tenk1;
+
+CREATE FUNCTION cursor_noscroll_scan() RETURNS bigint AS $$
+DECLARE
+ cur NO SCROLL CURSOR FOR SELECT * FROM cursor_buf_test;
+ rec RECORD;
+ cnt bigint := 0;
+BEGIN
+ OPEN cur;
+ LOOP
+ FETCH NEXT FROM cur INTO rec;
+ EXIT WHEN NOT FOUND;
+ cnt := cnt + 1;
+ END LOOP;
+ CLOSE cur;
+ RETURN cnt;
+END;
+$$ LANGUAGE plpgsql;
+
+CREATE FUNCTION cursor_scroll_scan() RETURNS bigint AS $$
+DECLARE
+ cur SCROLL CURSOR FOR SELECT * FROM cursor_buf_test;
+ rec RECORD;
+ cnt bigint := 0;
+BEGIN
+ OPEN cur;
+ LOOP
+ FETCH NEXT FROM cur INTO rec;
+ EXIT WHEN NOT FOUND;
+ cnt := cnt + 1;
+ END LOOP;
+ CLOSE cur;
+ RETURN cnt;
+END;
+$$ LANGUAGE plpgsql;
+
+CREATE FUNCTION check_cursor_explain_buffers() RETURNS TABLE(noscroll_ok boolean, scroll_ok boolean) AS $$
+DECLARE
+ plan_json json;
+ node json;
+ direct_buf int;
+ noscroll_buf int;
+ scroll_buf int;
+BEGIN
+ -- Direct scan: get leaf Seq Scan node buffers as baseline
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT * FROM cursor_buf_test' INTO plan_json;
+ node := plan_json->0->'Plan';
+ WHILE node->'Plans' IS NOT NULL LOOP
+ node := node->'Plans'->0;
+ END LOOP;
+ direct_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Non-scrollable cursor path: ExecShutdownNode runs after each ExecutorRun
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT cursor_noscroll_scan()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ noscroll_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Scrollable cursor path: ExecShutdownNode is skipped
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ SELECT cursor_scroll_scan()' INTO plan_json;
+ node := plan_json->0->'Plan';
+ scroll_buf :=
+ COALESCE((node->>'Local Hit Blocks')::int, 0) +
+ COALESCE((node->>'Local Read Blocks')::int, 0);
+
+ -- Both cursor paths should report buffer counts about as high as
+ -- the direct scan (same data plus minor catalog overhead), and not
+ -- double-counted (< 2x the direct scan)
+ RETURN QUERY SELECT
+ (noscroll_buf >= direct_buf * 0.5 AND noscroll_buf < direct_buf * 2),
+ (scroll_buf >= direct_buf * 0.5 AND scroll_buf < direct_buf * 2);
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT * FROM check_cursor_explain_buffers();
+
+DROP FUNCTION check_cursor_explain_buffers;
+DROP FUNCTION cursor_noscroll_scan;
+DROP FUNCTION cursor_scroll_scan;
+DROP TABLE cursor_buf_test;
+
+-- Test trigger instrumentation.
+CREATE TEMP TABLE trig_test_tab (a int);
+CREATE TEMP TABLE trig_work_tab (a int);
+INSERT INTO trig_work_tab VALUES (1);
+
+CREATE FUNCTION trig_test_func() RETURNS trigger AS $$
+BEGIN
+ PERFORM * FROM trig_work_tab;
+ RETURN NEW;
+END;
+$$ LANGUAGE plpgsql;
+
+CREATE TRIGGER trig_test_trig
+ BEFORE INSERT ON trig_test_tab
+ FOR EACH ROW EXECUTE FUNCTION trig_test_func();
+
+CREATE FUNCTION check_trigger_explain_buffers() RETURNS boolean AS $$
+DECLARE
+ plan_json json;
+ trig json;
+BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF, FORMAT JSON)
+ INSERT INTO trig_test_tab VALUES (1)' INTO plan_json;
+ trig := plan_json->0->'Triggers'->0;
+ RETURN COALESCE((trig->>'Calls')::int, 0) > 0;
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT check_trigger_explain_buffers() AS trigger_buffers_visible;
+
+DROP FUNCTION check_trigger_explain_buffers;
+DROP TRIGGER trig_test_trig ON trig_test_tab;
+DROP FUNCTION trig_test_func;
+DROP TABLE trig_test_tab;
+DROP TABLE trig_work_tab;
--
2.47.1
[application/octet-stream] v15-0004-instrumentation-Allocate-queryDesc-totaltime-in-.patch (6.4K, 4-v15-0004-instrumentation-Allocate-queryDesc-totaltime-in-.patch)
download | inline diff:
From d444dcdd48f5712cfcae7e7f4cc8055f1c33f902 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Tue, 9 Sep 2025 02:16:59 -0700
Subject: [PATCH v15 4/9] instrumentation: Allocate queryDesc->totaltime in
ExecutorStart if needed
This introduces a new field, queryDesc->totaltime_options, that extensions
can use to indicate whether they need queryDesc->totaltime populated,
and with which instrumentation options. Extensions should take care to
only add options they need, instead of replacing the options of others.
This replaces the practice of extensions allocating queryDesc->totaltime
themselves, which required them to always use INSTRUMENT_ALL for the
options argument. If they wouldn't have, another extension could silently
be impacted by it. It also unnecessarily made extensions hooks worry
about being sure to allocate in the per-query memory context.
Adjust pg_stat_statements and auto_explain to match, and lower the
requested instrumentation level for auto_explain to INSTRUMENT_TIMER,
since the summary instrumentation it needs is only runtime.
Author: Lukas Fittl <[email protected]>
Reviewed-by:
Discussion:
---
contrib/auto_explain/auto_explain.c | 20 +++------------
.../pg_stat_statements/pg_stat_statements.c | 25 ++++++-------------
src/backend/executor/execMain.c | 9 +++++++
src/backend/tcop/pquery.c | 1 +
src/include/executor/execdesc.h | 4 ++-
5 files changed, 23 insertions(+), 36 deletions(-)
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index 39bf2543b70..2f882026b50 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -284,6 +284,9 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
if (auto_explain_enabled())
{
+ /* We're always interested in runtime */
+ queryDesc->totaltime_options |= INSTRUMENT_TIMER;
+
/* Enable per-node instrumentation iff log_analyze is required. */
if (auto_explain_log_analyze && (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0)
{
@@ -302,23 +305,6 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
prev_ExecutorStart(queryDesc, eflags);
else
standard_ExecutorStart(queryDesc, eflags);
-
- if (auto_explain_enabled())
- {
- /*
- * Set up to track total elapsed time in ExecutorRun. Make sure the
- * space is allocated in the per-query context so it will go away at
- * ExecutorEnd.
- */
- if (queryDesc->totaltime == NULL)
- {
- MemoryContext oldcxt;
-
- oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
- queryDesc->totaltime = InstrAlloc(INSTRUMENT_ALL);
- MemoryContextSwitchTo(oldcxt);
- }
- }
}
/*
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index b6863479e9f..346adb5599f 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -983,11 +983,6 @@ pgss_planner(Query *parse,
static void
pgss_ExecutorStart(QueryDesc *queryDesc, int eflags)
{
- if (prev_ExecutorStart)
- prev_ExecutorStart(queryDesc, eflags);
- else
- standard_ExecutorStart(queryDesc, eflags);
-
/*
* If query has queryId zero, don't track it. This prevents double
* counting of optimizable statements that are directly contained in
@@ -995,20 +990,14 @@ pgss_ExecutorStart(QueryDesc *queryDesc, int eflags)
*/
if (pgss_enabled(nesting_level) && queryDesc->plannedstmt->queryId != INT64CONST(0))
{
- /*
- * Set up to track total elapsed time in ExecutorRun. Make sure the
- * space is allocated in the per-query context so it will go away at
- * ExecutorEnd.
- */
- if (queryDesc->totaltime == NULL)
- {
- MemoryContext oldcxt;
-
- oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
- queryDesc->totaltime = InstrAlloc(INSTRUMENT_ALL);
- MemoryContextSwitchTo(oldcxt);
- }
+ /* Request all summary instrumentation, i.e. timing, buffers and WAL */
+ queryDesc->totaltime_options |= INSTRUMENT_ALL;
}
+
+ if (prev_ExecutorStart)
+ prev_ExecutorStart(queryDesc, eflags);
+ else
+ standard_ExecutorStart(queryDesc, eflags);
}
/*
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index b0f636bf8b6..7d74f6da402 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -250,6 +250,15 @@ standard_ExecutorStart(QueryDesc *queryDesc, int eflags)
estate->es_instrument = queryDesc->instrument_options;
estate->es_jit_flags = queryDesc->plannedstmt->jitFlags;
+ /*
+ * Set up query-level instrumentation if extensions have requested it via
+ * totaltime_options. Ensure an extension has not allocated totaltime
+ * itself.
+ */
+ Assert(queryDesc->totaltime == NULL);
+ if (queryDesc->totaltime_options)
+ queryDesc->totaltime = InstrQueryAlloc(queryDesc->totaltime_options);
+
/*
* Set up an AFTER-trigger statement context, unless told not to, or
* unless it's EXPLAIN-only mode (when ExecutorFinish won't be called).
diff --git a/src/backend/tcop/pquery.c b/src/backend/tcop/pquery.c
index d8fc75d0bb9..e27f26ecd83 100644
--- a/src/backend/tcop/pquery.c
+++ b/src/backend/tcop/pquery.c
@@ -86,6 +86,7 @@ CreateQueryDesc(PlannedStmt *plannedstmt,
qd->params = params; /* parameter values passed into query */
qd->queryEnv = queryEnv;
qd->instrument_options = instrument_options; /* instrumentation wanted? */
+ qd->totaltime_options = 0;
/* null these fields until set by ExecutorStart */
qd->tupDesc = NULL;
diff --git a/src/include/executor/execdesc.h b/src/include/executor/execdesc.h
index d3a57242844..0d76a1c173e 100644
--- a/src/include/executor/execdesc.h
+++ b/src/include/executor/execdesc.h
@@ -42,6 +42,8 @@ typedef struct QueryDesc
ParamListInfo params; /* param values being passed in */
QueryEnvironment *queryEnv; /* query environment passed in */
int instrument_options; /* OR of InstrumentOption flags */
+ int totaltime_options; /* OR of InstrumentOption flags for
+ * totaltime */
/* These fields are set by ExecutorStart */
TupleDesc tupDesc; /* descriptor for result tuples */
@@ -51,7 +53,7 @@ typedef struct QueryDesc
/* This field is set by ExecutePlan */
bool already_executed; /* true if previously executed */
- /* This is always set NULL by the core system, but plugins can change it */
+ /* This field is allocated by ExecutorRun if needed */
struct Instrumentation *totaltime; /* total time spent in ExecutorRun */
} QueryDesc;
--
2.47.1
[application/octet-stream] v15-0002-instrumentation-Replace-direct-changes-of-pgBuff.patch (9.0K, 5-v15-0002-instrumentation-Replace-direct-changes-of-pgBuff.patch)
download | inline diff:
From 38d92b532d00d078b0b8333b17411585a81b8289 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Thu, 26 Mar 2026 23:31:04 -0700
Subject: [PATCH v15 2/9] instrumentation: Replace direct changes of
pgBufferUsage/pgWalUsage with INSTR_* macros
This encapsulates the ownership of these globals better, and will allow
a subsequent refactoring.
Author: Lukas Fittl <[email protected]>
Reviewed-by: Andres Freund <[email protected]>
Reviewed-by: Zsolt Parragi <[email protected]>
Discussion: https://www.postgresql.org/message-id/flat/CAP53PkzZ3UotnRrrnXWAv%3DF4avRq9MQ8zU%2BbxoN9tpovEu6fGQ%40mail.gmail.com#fc7140e8af21e07a90a09d7e76b300c4
---
src/backend/access/transam/xlog.c | 10 +++++-----
src/backend/storage/buffer/bufmgr.c | 20 ++++++++++----------
src/backend/storage/buffer/localbuf.c | 6 +++---
src/backend/storage/file/buffile.c | 8 ++++----
src/backend/utils/activity/pgstat_io.c | 8 ++++----
src/include/executor/instrument.h | 19 +++++++++++++++++++
6 files changed, 45 insertions(+), 26 deletions(-)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index b82af9a85c0..470110f6774 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -1115,10 +1115,10 @@ XLogInsertRecord(XLogRecData *rdata,
/* Report WAL traffic to the instrumentation. */
if (inserted)
{
- pgWalUsage.wal_bytes += rechdr->xl_tot_len;
- pgWalUsage.wal_records++;
- pgWalUsage.wal_fpi += num_fpi;
- pgWalUsage.wal_fpi_bytes += fpi_bytes;
+ INSTR_WALUSAGE_ADD(wal_bytes, rechdr->xl_tot_len);
+ INSTR_WALUSAGE_INCR(wal_records);
+ INSTR_WALUSAGE_ADD(wal_fpi, num_fpi);
+ INSTR_WALUSAGE_ADD(wal_fpi_bytes, fpi_bytes);
/* Required for the flush of pending stats WAL data */
pgstat_report_fixed = true;
@@ -2097,7 +2097,7 @@ AdvanceXLInsertBuffer(XLogRecPtr upto, TimeLineID tli, bool opportunistic)
WriteRqst.Flush = InvalidXLogRecPtr;
XLogWrite(WriteRqst, tli, false);
LWLockRelease(WALWriteLock);
- pgWalUsage.wal_buffers_full++;
+ INSTR_WALUSAGE_INCR(wal_buffers_full);
TRACE_POSTGRESQL_WAL_BUFFER_WRITE_DIRTY_DONE();
/*
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index 3cc0b0bdd92..3e1c39160db 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -840,7 +840,7 @@ ReadRecentBuffer(RelFileLocator rlocator, ForkNumber forkNum, BlockNumber blockN
{
PinLocalBuffer(bufHdr, true);
- pgBufferUsage.local_blks_hit++;
+ INSTR_BUFUSAGE_INCR(local_blks_hit);
return true;
}
@@ -861,7 +861,7 @@ ReadRecentBuffer(RelFileLocator rlocator, ForkNumber forkNum, BlockNumber blockN
{
if (BufferTagsEqual(&tag, &bufHdr->tag))
{
- pgBufferUsage.shared_blks_hit++;
+ INSTR_BUFUSAGE_INCR(shared_blks_hit);
return true;
}
UnpinBuffer(bufHdr);
@@ -1684,9 +1684,9 @@ TrackBufferHit(IOObject io_object, IOContext io_context,
true);
if (persistence == RELPERSISTENCE_TEMP)
- pgBufferUsage.local_blks_hit += 1;
+ INSTR_BUFUSAGE_INCR(local_blks_hit);
else
- pgBufferUsage.shared_blks_hit += 1;
+ INSTR_BUFUSAGE_INCR(shared_blks_hit);
pgstat_count_io_op(io_object, io_context, IOOP_HIT, 1, 0);
@@ -2148,9 +2148,9 @@ AsyncReadBuffers(ReadBuffersOperation *operation, int *nblocks_progress)
io_start, 1, io_buffers_len * BLCKSZ);
if (persistence == RELPERSISTENCE_TEMP)
- pgBufferUsage.local_blks_read += io_buffers_len;
+ INSTR_BUFUSAGE_ADD(local_blks_read, io_buffers_len);
else
- pgBufferUsage.shared_blks_read += io_buffers_len;
+ INSTR_BUFUSAGE_ADD(shared_blks_read, io_buffers_len);
/*
* Track vacuum cost when issuing IO, not after waiting for it. Otherwise
@@ -3043,7 +3043,7 @@ ExtendBufferedRelShared(BufferManagerRelation bmr,
TerminateBufferIO(buf_hdr, false, BM_VALID, true, false);
}
- pgBufferUsage.shared_blks_written += extend_by;
+ INSTR_BUFUSAGE_ADD(shared_blks_written, extend_by);
*extended_by = extend_by;
@@ -3189,7 +3189,7 @@ MarkBufferDirty(Buffer buffer)
*/
if (!(old_buf_state & BM_DIRTY))
{
- pgBufferUsage.shared_blks_dirtied++;
+ INSTR_BUFUSAGE_INCR(shared_blks_dirtied);
if (VacuumCostActive)
VacuumCostBalance += VacuumCostPageDirty;
}
@@ -4601,7 +4601,7 @@ FlushBuffer(BufferDesc *buf, SMgrRelation reln, IOObject io_object,
pgstat_count_io_op_time(IOOBJECT_RELATION, io_context,
IOOP_WRITE, io_start, 1, BLCKSZ);
- pgBufferUsage.shared_blks_written++;
+ INSTR_BUFUSAGE_INCR(shared_blks_written);
/*
* Mark the buffer as clean and end the BM_IO_IN_PROGRESS state.
@@ -5796,7 +5796,7 @@ MarkSharedBufferDirtyHint(Buffer buffer, BufferDesc *bufHdr, uint64 lockstate,
UnlockBufHdr(bufHdr);
}
- pgBufferUsage.shared_blks_dirtied++;
+ INSTR_BUFUSAGE_INCR(shared_blks_dirtied);
if (VacuumCostActive)
VacuumCostBalance += VacuumCostPageDirty;
}
diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c
index 396da84b25c..851b99056d5 100644
--- a/src/backend/storage/buffer/localbuf.c
+++ b/src/backend/storage/buffer/localbuf.c
@@ -218,7 +218,7 @@ FlushLocalBuffer(BufferDesc *bufHdr, SMgrRelation reln)
/* Mark not-dirty */
TerminateLocalBufferIO(bufHdr, true, 0, false);
- pgBufferUsage.local_blks_written++;
+ INSTR_BUFUSAGE_INCR(local_blks_written);
}
static Buffer
@@ -479,7 +479,7 @@ ExtendBufferedRelLocal(BufferManagerRelation bmr,
*extended_by = extend_by;
- pgBufferUsage.local_blks_written += extend_by;
+ INSTR_BUFUSAGE_ADD(local_blks_written, extend_by);
return first_block;
}
@@ -510,7 +510,7 @@ MarkLocalBufferDirty(Buffer buffer)
buf_state = pg_atomic_read_u64(&bufHdr->state);
if (!(buf_state & BM_DIRTY))
- pgBufferUsage.local_blks_dirtied++;
+ INSTR_BUFUSAGE_INCR(local_blks_dirtied);
buf_state |= BM_DIRTY;
diff --git a/src/backend/storage/file/buffile.c b/src/backend/storage/file/buffile.c
index c4afe4d368a..8b501dfcadd 100644
--- a/src/backend/storage/file/buffile.c
+++ b/src/backend/storage/file/buffile.c
@@ -475,13 +475,13 @@ BufFileLoadBuffer(BufFile *file)
if (track_io_timing)
{
INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_ACCUM_DIFF(pgBufferUsage.temp_blk_read_time, io_time, io_start);
+ INSTR_BUFUSAGE_TIME_ACCUM_DIFF(temp_blk_read_time, io_time, io_start);
}
/* we choose not to advance curOffset here */
if (file->nbytes > 0)
- pgBufferUsage.temp_blks_read++;
+ INSTR_BUFUSAGE_INCR(temp_blks_read);
}
/*
@@ -549,13 +549,13 @@ BufFileDumpBuffer(BufFile *file)
if (track_io_timing)
{
INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_ACCUM_DIFF(pgBufferUsage.temp_blk_write_time, io_time, io_start);
+ INSTR_BUFUSAGE_TIME_ACCUM_DIFF(temp_blk_write_time, io_time, io_start);
}
file->curOffset += bytestowrite;
wpos += bytestowrite;
- pgBufferUsage.temp_blks_written++;
+ INSTR_BUFUSAGE_INCR(temp_blks_written);
}
file->dirty = false;
diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c
index 2be26e92283..e3829d7fe7c 100644
--- a/src/backend/utils/activity/pgstat_io.c
+++ b/src/backend/utils/activity/pgstat_io.c
@@ -135,17 +135,17 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op,
{
pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
if (io_object == IOOBJECT_RELATION)
- INSTR_TIME_ADD(pgBufferUsage.shared_blk_write_time, io_time);
+ INSTR_BUFUSAGE_TIME_ADD(shared_blk_write_time, io_time);
else if (io_object == IOOBJECT_TEMP_RELATION)
- INSTR_TIME_ADD(pgBufferUsage.local_blk_write_time, io_time);
+ INSTR_BUFUSAGE_TIME_ADD(local_blk_write_time, io_time);
}
else if (io_op == IOOP_READ)
{
pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time));
if (io_object == IOOBJECT_RELATION)
- INSTR_TIME_ADD(pgBufferUsage.shared_blk_read_time, io_time);
+ INSTR_BUFUSAGE_TIME_ADD(shared_blk_read_time, io_time);
else if (io_object == IOOBJECT_TEMP_RELATION)
- INSTR_TIME_ADD(pgBufferUsage.local_blk_read_time, io_time);
+ INSTR_BUFUSAGE_TIME_ADD(local_blk_read_time, io_time);
}
}
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index cc9fbb0e2f0..5261356dba6 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -154,4 +154,23 @@ extern void BufferUsageAccumDiff(BufferUsage *dst,
extern void WalUsageAccumDiff(WalUsage *dst, const WalUsage *add,
const WalUsage *sub);
+#define INSTR_BUFUSAGE_INCR(fld) do { \
+ pgBufferUsage.fld++; \
+ } while(0)
+#define INSTR_BUFUSAGE_ADD(fld,val) do { \
+ pgBufferUsage.fld += (val); \
+ } while(0)
+#define INSTR_BUFUSAGE_TIME_ADD(fld,val) do { \
+ INSTR_TIME_ADD(pgBufferUsage.fld, val); \
+ } while (0)
+#define INSTR_BUFUSAGE_TIME_ACCUM_DIFF(fld,endval,startval) do { \
+ INSTR_TIME_ACCUM_DIFF(pgBufferUsage.fld, endval, startval); \
+ } while (0)
+#define INSTR_WALUSAGE_INCR(fld) do { \
+ pgWalUsage.fld++; \
+ } while(0)
+#define INSTR_WALUSAGE_ADD(fld,val) do { \
+ pgWalUsage.fld += (val); \
+ } while(0)
+
#endif /* INSTRUMENT_H */
--
2.47.1
[application/octet-stream] v15-0001-instrumentation-Use-Instrumentation-instead-of-m.patch (19.2K, 6-v15-0001-instrumentation-Use-Instrumentation-instead-of-m.patch)
download | inline diff:
From ae4383e786599a06d95924276a0e414f131d344d Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sun, 5 Apr 2026 05:08:23 -0700
Subject: [PATCH v15 1/9] instrumentation: Use Instrumentation instead of
manual buffer tracking
This replaces different repeated code blocks that read pgBufferUsage /
pgWalUsage, and may have also been running a timer to measure activity,
with the new Instrumentation struct and associated helpers.
Author: Lukas Fittl <[email protected]>
Reviewed-by:
Discussion:
---
.../pg_stat_statements/pg_stat_statements.c | 62 +++++--------------
src/backend/access/heap/vacuumlazy.c | 15 +++--
src/backend/commands/analyze.c | 31 +++++-----
src/backend/commands/explain.c | 44 +++++++------
src/backend/commands/explain_dr.c | 53 ++++++----------
src/backend/commands/prepare.c | 28 ++++-----
src/include/commands/explain_dr.h | 5 +-
7 files changed, 91 insertions(+), 147 deletions(-)
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 025215fcc90..b6863479e9f 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -906,22 +906,16 @@ pgss_planner(Query *parse,
&& pgss_track_planning && query_string
&& parse->queryId != INT64CONST(0))
{
- instr_time start;
- instr_time duration;
- BufferUsage bufusage_start,
- bufusage;
- WalUsage walusage_start,
- walusage;
-
- /* We need to track buffer usage as the planner can access them. */
- bufusage_start = pgBufferUsage;
+ Instrumentation instr = {0};
/*
+ * We need to track buffer usage as the planner can access them.
+ *
* Similarly the planner could write some WAL records in some cases
* (e.g. setting a hint bit with those being WAL-logged)
*/
- walusage_start = pgWalUsage;
- INSTR_TIME_SET_CURRENT(start);
+ InstrInitOptions(&instr, INSTRUMENT_ALL);
+ InstrStart(&instr);
nesting_level++;
PG_TRY();
@@ -939,26 +933,17 @@ pgss_planner(Query *parse,
}
PG_END_TRY();
- INSTR_TIME_SET_CURRENT(duration);
- INSTR_TIME_SUBTRACT(duration, start);
-
- /* calc differences of buffer counters. */
- memset(&bufusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
-
- /* calc differences of WAL counters. */
- memset(&walusage, 0, sizeof(WalUsage));
- WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+ InstrStop(&instr);
pgss_store(query_string,
parse->queryId,
parse->stmt_location,
parse->stmt_len,
PGSS_PLAN,
- INSTR_TIME_GET_MILLISEC(duration),
+ INSTR_TIME_GET_MILLISEC(instr.total),
0,
- &bufusage,
- &walusage,
+ &instr.bufusage,
+ &instr.walusage,
NULL,
NULL,
0,
@@ -1151,17 +1136,11 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
!IsA(parsetree, ExecuteStmt) &&
!IsA(parsetree, PrepareStmt))
{
- instr_time start;
- instr_time duration;
uint64 rows;
- BufferUsage bufusage_start,
- bufusage;
- WalUsage walusage_start,
- walusage;
+ Instrumentation instr = {0};
- bufusage_start = pgBufferUsage;
- walusage_start = pgWalUsage;
- INSTR_TIME_SET_CURRENT(start);
+ InstrInitOptions(&instr, INSTRUMENT_ALL);
+ InstrStart(&instr);
nesting_level++;
PG_TRY();
@@ -1191,8 +1170,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
* former value, which'd otherwise be a good idea.
*/
- INSTR_TIME_SET_CURRENT(duration);
- INSTR_TIME_SUBTRACT(duration, start);
+ InstrStop(&instr);
/*
* Track the total number of rows retrieved or affected by the utility
@@ -1205,23 +1183,15 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
qc->commandTag == CMDTAG_REFRESH_MATERIALIZED_VIEW)) ?
qc->nprocessed : 0;
- /* calc differences of buffer counters. */
- memset(&bufusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
-
- /* calc differences of WAL counters. */
- memset(&walusage, 0, sizeof(WalUsage));
- WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
-
pgss_store(queryString,
saved_queryId,
saved_stmt_location,
saved_stmt_len,
PGSS_EXEC,
- INSTR_TIME_GET_MILLISEC(duration),
+ INSTR_TIME_GET_MILLISEC(instr.total),
rows,
- &bufusage,
- &walusage,
+ &instr.bufusage,
+ &instr.walusage,
NULL,
NULL,
0,
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 88c71cd85b6..30f589c9207 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -637,8 +637,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
TimestampTz starttime = 0;
PgStat_Counter startreadtime = 0,
startwritetime = 0;
- WalUsage startwalusage = pgWalUsage;
- BufferUsage startbufferusage = pgBufferUsage;
+ Instrumentation *instr = NULL;
ErrorContextCallback errcallback;
char **indnames = NULL;
Size dead_items_max_bytes = 0;
@@ -654,6 +653,8 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
startreadtime = pgStatBlockReadTime;
startwritetime = pgStatBlockWriteTime;
}
+ instr = InstrAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
+ InstrStart(instr);
}
/* Used for instrumentation and stats report */
@@ -984,14 +985,14 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
{
TimestampTz endtime = GetCurrentTimestamp();
+ InstrStop(instr);
+
if (verbose || params->log_vacuum_min_duration == 0 ||
TimestampDifferenceExceeds(starttime, endtime,
params->log_vacuum_min_duration))
{
long secs_dur;
int usecs_dur;
- WalUsage walusage;
- BufferUsage bufferusage;
StringInfoData buf;
char *msgfmt;
int32 diff;
@@ -1000,12 +1001,10 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
int64 total_blks_hit;
int64 total_blks_read;
int64 total_blks_dirtied;
+ BufferUsage bufferusage = instr->bufusage;
+ WalUsage walusage = instr->walusage;
TimestampDifference(starttime, endtime, &secs_dur, &usecs_dur);
- memset(&walusage, 0, sizeof(WalUsage));
- WalUsageAccumDiff(&walusage, &pgWalUsage, &startwalusage);
- memset(&bufferusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufferusage, &pgBufferUsage, &startbufferusage);
total_blks_hit = bufferusage.shared_blks_hit +
bufferusage.local_blks_hit;
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index 49a5cdf579c..8472fc0c280 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -309,9 +309,7 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
Oid save_userid;
int save_sec_context;
int save_nestlevel;
- WalUsage startwalusage = pgWalUsage;
- BufferUsage startbufferusage = pgBufferUsage;
- BufferUsage bufferusage;
+ Instrumentation *instr = NULL;
PgStat_Counter startreadtime = 0;
PgStat_Counter startwritetime = 0;
@@ -362,6 +360,9 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
}
pg_rusage_init(&ru0);
+
+ instr = InstrAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
+ InstrStart(instr);
}
/* Used for instrumentation and stats report */
@@ -742,12 +743,13 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
{
TimestampTz endtime = GetCurrentTimestamp();
+ InstrStop(instr);
+
if (verbose || params->log_analyze_min_duration == 0 ||
TimestampDifferenceExceeds(starttime, endtime,
params->log_analyze_min_duration))
{
long delay_in_ms;
- WalUsage walusage;
double read_rate = 0;
double write_rate = 0;
char *msgfmt;
@@ -755,18 +757,15 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
int64 total_blks_hit;
int64 total_blks_read;
int64 total_blks_dirtied;
-
- memset(&bufferusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufferusage, &pgBufferUsage, &startbufferusage);
- memset(&walusage, 0, sizeof(WalUsage));
- WalUsageAccumDiff(&walusage, &pgWalUsage, &startwalusage);
-
- total_blks_hit = bufferusage.shared_blks_hit +
- bufferusage.local_blks_hit;
- total_blks_read = bufferusage.shared_blks_read +
- bufferusage.local_blks_read;
- total_blks_dirtied = bufferusage.shared_blks_dirtied +
- bufferusage.local_blks_dirtied;
+ BufferUsage bufusage = instr->bufusage;
+ WalUsage walusage = instr->walusage;
+
+ total_blks_hit = bufusage.shared_blks_hit +
+ bufusage.local_blks_hit;
+ total_blks_read = bufusage.shared_blks_read +
+ bufusage.local_blks_read;
+ total_blks_dirtied = bufusage.shared_blks_dirtied +
+ bufusage.local_blks_dirtied;
/*
* We do not expect an analyze to take > 25 days and it simplifies
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 73eaaf176ac..d6dc7268438 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -324,14 +324,17 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
QueryEnvironment *queryEnv)
{
PlannedStmt *plan;
- instr_time planstart,
- planduration;
- BufferUsage bufusage_start,
- bufusage;
+ Instrumentation plan_instr = {0};
+ int instrument_options = INSTRUMENT_TIMER;
MemoryContextCounters mem_counters;
MemoryContext planner_ctx = NULL;
MemoryContext saved_ctx = NULL;
+ if (es->buffers)
+ instrument_options |= INSTRUMENT_BUFFERS;
+
+ InstrInitOptions(&plan_instr, instrument_options);
+
if (es->memory)
{
/*
@@ -348,15 +351,12 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
saved_ctx = MemoryContextSwitchTo(planner_ctx);
}
- if (es->buffers)
- bufusage_start = pgBufferUsage;
- INSTR_TIME_SET_CURRENT(planstart);
+ InstrStart(&plan_instr);
/* plan the query */
plan = pg_plan_query(query, queryString, cursorOptions, params, es);
- INSTR_TIME_SET_CURRENT(planduration);
- INSTR_TIME_SUBTRACT(planduration, planstart);
+ InstrStop(&plan_instr);
if (es->memory)
{
@@ -364,16 +364,9 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
MemoryContextMemConsumed(planner_ctx, &mem_counters);
}
- /* calc differences of buffer counters. */
- if (es->buffers)
- {
- memset(&bufusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
- }
-
/* run it (if needed) and produce output */
ExplainOnePlan(plan, into, es, queryString, params, queryEnv,
- &planduration, (es->buffers ? &bufusage : NULL),
+ &plan_instr.total, (es->buffers ? &plan_instr.bufusage : NULL),
es->memory ? &mem_counters : NULL);
}
@@ -590,7 +583,12 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* grab serialization metrics before we destroy the DestReceiver */
if (es->serialize != EXPLAIN_SERIALIZE_NONE)
- serializeMetrics = GetSerializationMetrics(dest);
+ {
+ SerializeMetrics *metrics = GetSerializationMetrics(dest);
+
+ if (metrics)
+ memcpy(&serializeMetrics, metrics, sizeof(SerializeMetrics));
+ }
/* call the DestReceiver's destroy method even during explain */
dest->rDestroy(dest);
@@ -1019,7 +1017,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
ExplainIndentText(es);
if (es->timing)
appendStringInfo(es->str, "Serialization: time=%.3f ms output=" UINT64_FORMAT "kB format=%s\n",
- 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
+ 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->instr.total),
BYTES_TO_KILOBYTES(metrics->bytesSent),
format);
else
@@ -1027,10 +1025,10 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
BYTES_TO_KILOBYTES(metrics->bytesSent),
format);
- if (es->buffers && peek_buffer_usage(es, &metrics->bufferUsage))
+ if (es->buffers && peek_buffer_usage(es, &metrics->instr.bufusage))
{
es->indent++;
- show_buffer_usage(es, &metrics->bufferUsage);
+ show_buffer_usage(es, &metrics->instr.bufusage);
es->indent--;
}
}
@@ -1038,13 +1036,13 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
{
if (es->timing)
ExplainPropertyFloat("Time", "ms",
- 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
+ 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->instr.total),
3, es);
ExplainPropertyUInteger("Output Volume", "kB",
BYTES_TO_KILOBYTES(metrics->bytesSent), es);
ExplainPropertyText("Format", format, es);
if (es->buffers)
- show_buffer_usage(es, &metrics->bufferUsage);
+ show_buffer_usage(es, &metrics->instr.bufusage);
}
ExplainCloseGroup("Serialization", "Serialization", true, es);
diff --git a/src/backend/commands/explain_dr.c b/src/backend/commands/explain_dr.c
index 3c96061cf32..df5ae5f4569 100644
--- a/src/backend/commands/explain_dr.c
+++ b/src/backend/commands/explain_dr.c
@@ -110,15 +110,10 @@ serializeAnalyzeReceive(TupleTableSlot *slot, DestReceiver *self)
MemoryContext oldcontext;
StringInfo buf = &myState->buf;
int natts = typeinfo->natts;
- instr_time start,
- end;
- BufferUsage instr_start;
+ Instrumentation *instr = &myState->metrics.instr;
- /* only measure time, buffers if requested */
- if (myState->es->timing)
- INSTR_TIME_SET_CURRENT(start);
- if (myState->es->buffers)
- instr_start = pgBufferUsage;
+ /* Start per-tuple measurement */
+ InstrStart(instr);
/* Set or update my derived attribute info, if needed */
if (myState->attrinfo != typeinfo || myState->nattrs != natts)
@@ -186,18 +181,8 @@ serializeAnalyzeReceive(TupleTableSlot *slot, DestReceiver *self)
MemoryContextSwitchTo(oldcontext);
MemoryContextReset(myState->tmpcontext);
- /* Update timing data */
- if (myState->es->timing)
- {
- INSTR_TIME_SET_CURRENT(end);
- INSTR_TIME_ACCUM_DIFF(myState->metrics.timeSpent, end, start);
- }
-
- /* Update buffer metrics */
- if (myState->es->buffers)
- BufferUsageAccumDiff(&myState->metrics.bufferUsage,
- &pgBufferUsage,
- &instr_start);
+ /* Stop per-tuple measurement */
+ InstrStop(instr);
return true;
}
@@ -209,6 +194,7 @@ static void
serializeAnalyzeStartup(DestReceiver *self, int operation, TupleDesc typeinfo)
{
SerializeDestReceiver *receiver = (SerializeDestReceiver *) self;
+ int instrument_options = 0;
Assert(receiver->es != NULL);
@@ -233,9 +219,13 @@ serializeAnalyzeStartup(DestReceiver *self, int operation, TupleDesc typeinfo)
/* The output buffer is re-used across rows, as in printtup.c */
initStringInfo(&receiver->buf);
- /* Initialize results counters */
+ /* Initialize metrics and per-tuple instrumentation */
memset(&receiver->metrics, 0, sizeof(SerializeMetrics));
- INSTR_TIME_SET_ZERO(receiver->metrics.timeSpent);
+ if (receiver->es->timing)
+ instrument_options |= INSTRUMENT_TIMER;
+ if (receiver->es->buffers)
+ instrument_options |= INSTRUMENT_BUFFERS;
+ InstrInitOptions(&receiver->metrics.instr, instrument_options);
}
/*
@@ -290,22 +280,17 @@ CreateExplainSerializeDestReceiver(ExplainState *es)
}
/*
- * GetSerializationMetrics - collect metrics
+ * GetSerializationMetrics - get serialization metrics
*
- * We have to be careful here since the receiver could be an IntoRel
- * receiver if the subject statement is CREATE TABLE AS. In that
- * case, return all-zeroes stats.
+ * Returns a pointer to the SerializeMetrics inside the dest receiver,
+ * or NULL if the receiver is not a SerializeDestReceiver (e.g. an IntoRel
+ * receiver for CREATE TABLE AS).
*/
-SerializeMetrics
+SerializeMetrics *
GetSerializationMetrics(DestReceiver *dest)
{
- SerializeMetrics empty;
-
if (dest->mydest == DestExplainSerialize)
- return ((SerializeDestReceiver *) dest)->metrics;
-
- memset(&empty, 0, sizeof(SerializeMetrics));
- INSTR_TIME_SET_ZERO(empty.timeSpent);
+ return &((SerializeDestReceiver *) dest)->metrics;
- return empty;
+ return NULL;
}
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index 876aad2100a..bf9f2eb6149 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -22,6 +22,7 @@
#include "catalog/pg_type.h"
#include "commands/createas.h"
#include "commands/explain.h"
+#include "executor/instrument.h"
#include "commands/explain_format.h"
#include "commands/explain_state.h"
#include "commands/prepare.h"
@@ -580,14 +581,17 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
ListCell *p;
ParamListInfo paramLI = NULL;
EState *estate = NULL;
- instr_time planstart;
- instr_time planduration;
- BufferUsage bufusage_start,
- bufusage;
+ Instrumentation plan_instr = {0};
+ int instrument_options = INSTRUMENT_TIMER;
MemoryContextCounters mem_counters;
MemoryContext planner_ctx = NULL;
MemoryContext saved_ctx = NULL;
+ if (es->buffers)
+ instrument_options |= INSTRUMENT_BUFFERS;
+
+ InstrInitOptions(&plan_instr, instrument_options);
+
if (es->memory)
{
/* See ExplainOneQuery about this */
@@ -598,9 +602,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
saved_ctx = MemoryContextSwitchTo(planner_ctx);
}
- if (es->buffers)
- bufusage_start = pgBufferUsage;
- INSTR_TIME_SET_CURRENT(planstart);
+ InstrStart(&plan_instr);
/* Look it up in the hash table */
entry = FetchPreparedStatement(execstmt->name, true);
@@ -635,8 +637,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
cplan = GetCachedPlan(entry->plansource, paramLI,
CurrentResourceOwner, pstate->p_queryEnv);
- INSTR_TIME_SET_CURRENT(planduration);
- INSTR_TIME_SUBTRACT(planduration, planstart);
+ InstrStop(&plan_instr);
if (es->memory)
{
@@ -644,13 +645,6 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
MemoryContextMemConsumed(planner_ctx, &mem_counters);
}
- /* calc differences of buffer counters. */
- if (es->buffers)
- {
- memset(&bufusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
- }
-
plan_list = cplan->stmt_list;
/* Explain each query */
@@ -660,7 +654,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
if (pstmt->commandType != CMD_UTILITY)
ExplainOnePlan(pstmt, into, es, query_string, paramLI, pstate->p_queryEnv,
- &planduration, (es->buffers ? &bufusage : NULL),
+ &plan_instr.total, (es->buffers ? &plan_instr.bufusage : NULL),
es->memory ? &mem_counters : NULL);
else
ExplainOneUtility(pstmt->utilityStmt, into, es, pstate, paramLI);
diff --git a/src/include/commands/explain_dr.h b/src/include/commands/explain_dr.h
index f98eaae1864..ab5c53023e1 100644
--- a/src/include/commands/explain_dr.h
+++ b/src/include/commands/explain_dr.h
@@ -23,11 +23,10 @@ typedef struct ExplainState ExplainState;
typedef struct SerializeMetrics
{
uint64 bytesSent; /* # of bytes serialized */
- instr_time timeSpent; /* time spent serializing */
- BufferUsage bufferUsage; /* buffers accessed during serialization */
+ Instrumentation instr; /* time and buffer usage */
} SerializeMetrics;
extern DestReceiver *CreateExplainSerializeDestReceiver(ExplainState *es);
-extern SerializeMetrics GetSerializationMetrics(DestReceiver *dest);
+extern SerializeMetrics *GetSerializationMetrics(DestReceiver *dest);
#endif
--
2.47.1
[application/octet-stream] v15-0007-instrumentation-Optimize-ExecProcNodeInstr-instr.patch (9.4K, 7-v15-0007-instrumentation-Optimize-ExecProcNodeInstr-instr.patch)
download | inline diff:
From 9e527947d49be7715cb01addda2890ff54ed5c16 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sun, 5 Apr 2026 19:30:56 -0700
Subject: [PATCH v15 7/9] instrumentation: Optimize ExecProcNodeInstr
instructions by inlining
For most queries, the bulk of the overhead of EXPLAIN ANALYZE happens in
ExecProcNodeInstr when starting/stopping instrumentation for that node.
Previously each ExecProcNodeInstr would check which instrumentation
options are active in the InstrStartNode/InstrStopNode calls, and do the
corresponding work (timers, instrumentation stack, etc.). These
conditionals being checked for each tuple being emitted add up, and cause
non-optimal set of instructions to be generated by the compiler.
Because we already have an existing mechanism to specify a function
pointer when instrumentation is enabled, we can instead create specialized
functions that are tailored to the instrumentation options enabled, and
avoid conditionals on subsequent ExecProcNodeInstr calls. This results in
the overhead for EXPLAIN (ANALYZE, TIMING OFF, BUFFERS OFF) for a stress
test with a large COUNT(*) that does many ExecProcNode calls from ~ 20% on
top of actual runtime to ~ 3%. When using BUFFERS ON the same query goes
from ~ 20% to ~ 10% on top of actual runtime.
Author: Lukas Fittl <[email protected]>
Reviewed-by: Zsolt Parragi <[email protected]>
Discussion: https://www.postgresql.org/message-id/flat/CAP53PkxFP7i7-wy98ZmEJ11edYq-RrPvJoa4kzGhBBjERA4Nyw%40mail.gmail.com#e8dfd018a07d7f8d41565a079d40c564
---
src/backend/executor/execProcnode.c | 22 +----
src/backend/executor/instrument.c | 144 ++++++++++++++++++++++++----
src/include/executor/instrument.h | 5 +
3 files changed, 130 insertions(+), 41 deletions(-)
diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c
index f006931c94d..ac400670fea 100644
--- a/src/backend/executor/execProcnode.c
+++ b/src/backend/executor/execProcnode.c
@@ -121,7 +121,6 @@
#include "nodes/nodeFuncs.h"
static TupleTableSlot *ExecProcNodeFirst(PlanState *node);
-static TupleTableSlot *ExecProcNodeInstr(PlanState *node);
static bool ExecShutdownNode_walker(PlanState *node, void *context);
static bool ExecFinalizeNodeInstrumentation_walker(PlanState *node, void *context);
static bool ExecFinalizeWorkerInstrumentation_walker(PlanState *node, void *context);
@@ -466,7 +465,7 @@ ExecProcNodeFirst(PlanState *node)
* have ExecProcNode() directly call the relevant function from now on.
*/
if (node->instrument)
- node->ExecProcNode = ExecProcNodeInstr;
+ node->ExecProcNode = InstrNodeSetupExecProcNode(node->instrument);
else
node->ExecProcNode = node->ExecProcNodeReal;
@@ -474,25 +473,6 @@ ExecProcNodeFirst(PlanState *node)
}
-/*
- * ExecProcNode wrapper that performs instrumentation calls. By keeping
- * this a separate function, we avoid overhead in the normal case where
- * no instrumentation is wanted.
- */
-static TupleTableSlot *
-ExecProcNodeInstr(PlanState *node)
-{
- TupleTableSlot *result;
-
- InstrStartNode(node->instrument);
-
- result = node->ExecProcNodeReal(node);
-
- InstrStopNode(node->instrument, TupIsNull(result) ? 0.0 : 1.0);
-
- return result;
-}
-
/* ----------------------------------------------------------------
* MultiExecProcNode
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index cfedbad0eba..5a17be9aa53 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -66,19 +66,25 @@ InstrInitOptions(Instrumentation *instr, int instrument_options)
instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
}
-void
-InstrStart(Instrumentation *instr)
+static inline void
+InstrStartTimer(Instrumentation *instr)
{
- if (instr->need_timer)
- {
- if (!INSTR_TIME_IS_ZERO(instr->starttime))
- elog(ERROR, "InstrStart called twice in a row");
- else
- INSTR_TIME_SET_CURRENT(instr->starttime);
- }
+ Assert(INSTR_TIME_IS_ZERO(instr->starttime));
- if (instr->need_stack)
- InstrPushStack(instr);
+ INSTR_TIME_SET_CURRENT(instr->starttime);
+}
+
+static inline void
+InstrStopTimer(Instrumentation *instr, instr_time *accum_time)
+{
+ instr_time endtime;
+
+ Assert(!INSTR_TIME_IS_ZERO(instr->starttime));
+
+ INSTR_TIME_SET_CURRENT(endtime);
+ INSTR_TIME_ACCUM_DIFF(*accum_time, endtime, instr->starttime);
+
+ INSTR_TIME_SET_ZERO(instr->starttime);
}
/*
@@ -88,18 +94,13 @@ InstrStart(Instrumentation *instr)
static inline void
InstrStopCommon(Instrumentation *instr, instr_time *accum_time)
{
- instr_time endtime;
-
/* update the time only if the timer was requested */
if (instr->need_timer)
{
if (INSTR_TIME_IS_ZERO(instr->starttime))
elog(ERROR, "InstrStop called without start");
- INSTR_TIME_SET_CURRENT(endtime);
- INSTR_TIME_ACCUM_DIFF(*accum_time, endtime, instr->starttime);
-
- INSTR_TIME_SET_ZERO(instr->starttime);
+ InstrStopTimer(instr, accum_time);
}
/* pop the stack, unless InstrStopFinalize previously cleaned up */
@@ -107,6 +108,16 @@ InstrStopCommon(Instrumentation *instr, instr_time *accum_time)
InstrPopStack(instr);
}
+void
+InstrStart(Instrumentation *instr)
+{
+ if (instr->need_timer)
+ InstrStartTimer(instr);
+
+ if (instr->need_stack)
+ InstrPushStack(instr);
+}
+
void
InstrStop(Instrumentation *instr)
{
@@ -398,15 +409,14 @@ InstrInitNode(NodeInstrumentation *instr, int instrument_options, bool async_mod
instr->async_mode = async_mode;
}
-/* Entry to a plan node */
+/* Entry to a plan node. If you modify this, check InstrNodeSetupExecProcNode. */
void
InstrStartNode(NodeInstrumentation *instr)
{
InstrStart(&instr->instr);
}
-
-/* Exit from a plan node */
+/* Exit from a plan node. If you modify this, check InstrNodeSetupExecProcNode. */
void
InstrStopNode(NodeInstrumentation *instr, double nTuples)
{
@@ -495,6 +505,100 @@ InstrAggNode(NodeInstrumentation *dst, NodeInstrumentation *add)
InstrAccumStack(&dst->instr, &add->instr);
}
+/*
+ * Specialized handling of instrumented ExecProcNode
+ *
+ * These functions are equivalent to running ExecProcNodeReal wrapped in
+ * InstrStartNode and InstrStopNode, but avoid the conditionals in the hot path
+ * by checking the instrumentation options when the ExecProcNode pointer gets
+ * first set, and then using a special-purpose function for each. This results
+ * in a more optimized set of compiled instructions.
+ */
+
+#include "executor/tuptable.h"
+#include "nodes/execnodes.h"
+
+/* Simplified pop: restore saved state instead of re-deriving from array */
+static inline void
+InstrPopStackTo(Instrumentation *prev)
+{
+ Assert(instr_stack.stack_size > 0);
+ Assert(instr_stack.stack_size > 1 ? instr_stack.entries[instr_stack.stack_size - 2] == prev : &instr_top == prev);
+ instr_stack.entries[instr_stack.stack_size - 1]->on_stack = false;
+ instr_stack.stack_size--;
+ instr_stack.current = prev;
+}
+
+static pg_attribute_always_inline TupleTableSlot *
+ExecProcNodeInstr(PlanState *node, bool need_timer, bool need_stack)
+{
+ NodeInstrumentation *instr = node->instrument;
+ Instrumentation *prev = instr_stack.current;
+ TupleTableSlot *result;
+
+ if (need_stack)
+ InstrPushStack(&instr->instr);
+ if (need_timer)
+ InstrStartTimer(&instr->instr);
+
+ result = node->ExecProcNodeReal(node);
+
+ if (need_timer)
+ InstrStopTimer(&instr->instr, &instr->counter);
+ if (need_stack)
+ InstrPopStackTo(prev);
+
+ instr->running = true;
+ if (!TupIsNull(result))
+ instr->tuplecount += 1.0;
+
+ return result;
+}
+
+static TupleTableSlot *
+ExecProcNodeInstrFull(PlanState *node)
+{
+ return ExecProcNodeInstr(node, true, true);
+}
+
+static TupleTableSlot *
+ExecProcNodeInstrRowsStackOnly(PlanState *node)
+{
+ return ExecProcNodeInstr(node, false, true);
+}
+
+static TupleTableSlot *
+ExecProcNodeInstrRowsTimerOnly(PlanState *node)
+{
+ return ExecProcNodeInstr(node, true, false);
+}
+
+static TupleTableSlot *
+ExecProcNodeInstrRowsOnly(PlanState *node)
+{
+ return ExecProcNodeInstr(node, false, false);
+}
+
+/*
+ * Returns an ExecProcNode wrapper that performs instrumentation calls,
+ * tailored to the instrumentation options enabled for the node.
+ */
+ExecProcNodeMtd
+InstrNodeSetupExecProcNode(NodeInstrumentation *instr)
+{
+ bool need_timer = instr->instr.need_timer;
+ bool need_stack = instr->instr.need_stack;
+
+ if (need_timer && need_stack)
+ return ExecProcNodeInstrFull;
+ else if (need_stack)
+ return ExecProcNodeInstrRowsStackOnly;
+ else if (need_timer)
+ return ExecProcNodeInstrRowsTimerOnly;
+ else
+ return ExecProcNodeInstrRowsOnly;
+}
+
/* Trigger instrumentation handling */
TriggerInstrumentation *
InstrAllocTrigger(QueryInstrumentation *qinstr, int instrument_options, int n)
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 5bb698d686d..bd481afd0de 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -300,6 +300,11 @@ extern void InstrUpdateTupleCount(NodeInstrumentation *instr, double nTuples);
extern void InstrEndLoop(NodeInstrumentation *instr);
extern void InstrAggNode(NodeInstrumentation *dst, NodeInstrumentation *add);
+typedef struct TupleTableSlot TupleTableSlot;
+typedef struct PlanState PlanState;
+typedef TupleTableSlot *(*ExecProcNodeMtd) (PlanState *pstate);
+extern ExecProcNodeMtd InstrNodeSetupExecProcNode(NodeInstrumentation *instr);
+
extern TriggerInstrumentation *InstrAllocTrigger(QueryInstrumentation *qinstr,
int instrument_options, int n);
extern void InstrStartTrigger(TriggerInstrumentation *tginstr);
--
2.47.1
[application/octet-stream] v15-0006-instrumentation-Use-Instrumentation-struct-for-p.patch (29.1K, 8-v15-0006-instrumentation-Use-Instrumentation-struct-for-p.patch)
download | inline diff:
From 90128ad03216fab0a0d62a3521694f9dc1a93b52 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sun, 15 Mar 2026 21:44:58 -0700
Subject: [PATCH v15 6/9] instrumentation: Use Instrumentation struct for
parallel workers
This simplifies the DSM allocations a bit since we don't need to
separately allocate WAL and buffer usage, and allows the easier future
addition of a third stack-based struct being discussed.
Author: Lukas Fittl <[email protected]>
Reviewed-by:
Discussion:
---
src/backend/access/brin/brin.c | 43 ++++++-----------
src/backend/access/gin/gininsert.c | 43 ++++++-----------
src/backend/access/nbtree/nbtsort.c | 43 ++++++-----------
src/backend/commands/vacuumparallel.c | 52 ++++++++-------------
src/backend/executor/execParallel.c | 66 ++++++++++++---------------
src/backend/executor/instrument.c | 14 +++---
src/include/executor/execParallel.h | 5 +-
src/include/executor/instrument.h | 4 +-
8 files changed, 99 insertions(+), 171 deletions(-)
diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index 3a5176c76c7..9e545b4ef0e 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -51,8 +51,7 @@
#define PARALLEL_KEY_BRIN_SHARED UINT64CONST(0xB000000000000001)
#define PARALLEL_KEY_TUPLESORT UINT64CONST(0xB000000000000002)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xB000000000000003)
-#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xB000000000000004)
-#define PARALLEL_KEY_BUFFER_USAGE UINT64CONST(0xB000000000000005)
+#define PARALLEL_KEY_INSTRUMENTATION UINT64CONST(0xB000000000000004)
/*
* Status for index builds performed in parallel. This is allocated in a
@@ -148,8 +147,7 @@ typedef struct BrinLeader
BrinShared *brinshared;
Sharedsort *sharedsort;
Snapshot snapshot;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
} BrinLeader;
/*
@@ -2387,8 +2385,7 @@ _brin_begin_parallel(BrinBuildState *buildstate, Relation heap, Relation index,
BrinShared *brinshared;
Sharedsort *sharedsort;
BrinLeader *brinleader = palloc0_object(BrinLeader);
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
bool leaderparticipates = true;
int querylen;
@@ -2430,18 +2427,14 @@ _brin_begin_parallel(BrinBuildState *buildstate, Relation heap, Relation index,
shm_toc_estimate_keys(&pcxt->estimator, 2);
/*
- * Estimate space for WalUsage and BufferUsage -- PARALLEL_KEY_WAL_USAGE
- * and PARALLEL_KEY_BUFFER_USAGE.
+ * Estimate space for Instrumentation -- PARALLEL_KEY_INSTRUMENTATION.
*
* If there are no extensions loaded that care, we could skip this. We
* have no way of knowing whether anyone's looking at instrumentation, so
* do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_estimate_keys(&pcxt->estimator, 1);
- shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_KEY_QUERY_TEXT space */
@@ -2514,15 +2507,12 @@ _brin_begin_parallel(BrinBuildState *buildstate, Relation heap, Relation index,
}
/*
- * Allocate space for each worker's WalUsage and BufferUsage; no need to
+ * Allocate space for each worker's Instrumentation; no need to
* initialize.
*/
- walusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage);
- bufferusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufferusage);
+ instr = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_INSTRUMENTATION, instr);
/* Launch workers, saving status for leader/caller */
LaunchParallelWorkers(pcxt);
@@ -2533,8 +2523,7 @@ _brin_begin_parallel(BrinBuildState *buildstate, Relation heap, Relation index,
brinleader->brinshared = brinshared;
brinleader->sharedsort = sharedsort;
brinleader->snapshot = snapshot;
- brinleader->walusage = walusage;
- brinleader->bufferusage = bufferusage;
+ brinleader->instr = instr;
/* If no workers were successfully launched, back out (do serial build) */
if (pcxt->nworkers_launched == 0)
@@ -2573,7 +2562,7 @@ _brin_end_parallel(BrinLeader *brinleader, BrinBuildState *state)
* or we might get incomplete data.)
*/
for (i = 0; i < brinleader->pcxt->nworkers_launched; i++)
- InstrAccumParallelQuery(&brinleader->bufferusage[i], &brinleader->walusage[i]);
+ InstrAccumParallelQuery(&brinleader->instr[i]);
/* Free last reference to MVCC snapshot, if one was used */
if (IsMVCCSnapshot(brinleader->snapshot))
@@ -2888,8 +2877,7 @@ _brin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
QueryInstrumentation *instr;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *worker_instr;
int sortmem;
/*
@@ -2950,11 +2938,8 @@ _brin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
heapRel, indexRel, sortmem, false);
/* Report WAL/buffer usage during parallel execution */
- bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(instr,
- &bufferusage[ParallelWorkerNumber],
- &walusage[ParallelWorkerNumber]);
+ worker_instr = shm_toc_lookup(toc, PARALLEL_KEY_INSTRUMENTATION, false);
+ InstrEndParallelQuery(instr, &worker_instr[ParallelWorkerNumber]);
index_close(indexRel, indexLockmode);
table_close(heapRel, heapLockmode);
diff --git a/src/backend/access/gin/gininsert.c b/src/backend/access/gin/gininsert.c
index 0d80f72a0b0..f3de62ce7f3 100644
--- a/src/backend/access/gin/gininsert.c
+++ b/src/backend/access/gin/gininsert.c
@@ -45,8 +45,7 @@
#define PARALLEL_KEY_GIN_SHARED UINT64CONST(0xB000000000000001)
#define PARALLEL_KEY_TUPLESORT UINT64CONST(0xB000000000000002)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xB000000000000003)
-#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xB000000000000004)
-#define PARALLEL_KEY_BUFFER_USAGE UINT64CONST(0xB000000000000005)
+#define PARALLEL_KEY_INSTRUMENTATION UINT64CONST(0xB000000000000004)
/*
* Status for index builds performed in parallel. This is allocated in a
@@ -138,8 +137,7 @@ typedef struct GinLeader
GinBuildShared *ginshared;
Sharedsort *sharedsort;
Snapshot snapshot;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
} GinLeader;
typedef struct
@@ -945,8 +943,7 @@ _gin_begin_parallel(GinBuildState *buildstate, Relation heap, Relation index,
GinBuildShared *ginshared;
Sharedsort *sharedsort;
GinLeader *ginleader = palloc0_object(GinLeader);
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
bool leaderparticipates = true;
int querylen;
@@ -987,18 +984,14 @@ _gin_begin_parallel(GinBuildState *buildstate, Relation heap, Relation index,
shm_toc_estimate_keys(&pcxt->estimator, 2);
/*
- * Estimate space for WalUsage and BufferUsage -- PARALLEL_KEY_WAL_USAGE
- * and PARALLEL_KEY_BUFFER_USAGE.
+ * Estimate space for Instrumentation -- PARALLEL_KEY_INSTRUMENTATION.
*
* If there are no extensions loaded that care, we could skip this. We
* have no way of knowing whether anyone's looking at instrumentation, so
* do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_estimate_keys(&pcxt->estimator, 1);
- shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_KEY_QUERY_TEXT space */
@@ -1066,15 +1059,12 @@ _gin_begin_parallel(GinBuildState *buildstate, Relation heap, Relation index,
}
/*
- * Allocate space for each worker's WalUsage and BufferUsage; no need to
+ * Allocate space for each worker's Instrumentation; no need to
* initialize.
*/
- walusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage);
- bufferusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufferusage);
+ instr = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_INSTRUMENTATION, instr);
/* Launch workers, saving status for leader/caller */
LaunchParallelWorkers(pcxt);
@@ -1085,8 +1075,7 @@ _gin_begin_parallel(GinBuildState *buildstate, Relation heap, Relation index,
ginleader->ginshared = ginshared;
ginleader->sharedsort = sharedsort;
ginleader->snapshot = snapshot;
- ginleader->walusage = walusage;
- ginleader->bufferusage = bufferusage;
+ ginleader->instr = instr;
/* If no workers were successfully launched, back out (do serial build) */
if (pcxt->nworkers_launched == 0)
@@ -1125,7 +1114,7 @@ _gin_end_parallel(GinLeader *ginleader, GinBuildState *state)
* or we might get incomplete data.)
*/
for (i = 0; i < ginleader->pcxt->nworkers_launched; i++)
- InstrAccumParallelQuery(&ginleader->bufferusage[i], &ginleader->walusage[i]);
+ InstrAccumParallelQuery(&ginleader->instr[i]);
/* Free last reference to MVCC snapshot, if one was used */
if (IsMVCCSnapshot(ginleader->snapshot))
@@ -2119,8 +2108,7 @@ _gin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
QueryInstrumentation *instr;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *worker_instr;
int sortmem;
/*
@@ -2200,11 +2188,8 @@ _gin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
heapRel, indexRel, sortmem, false);
/* Report WAL/buffer usage during parallel execution */
- bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(instr,
- &bufferusage[ParallelWorkerNumber],
- &walusage[ParallelWorkerNumber]);
+ worker_instr = shm_toc_lookup(toc, PARALLEL_KEY_INSTRUMENTATION, false);
+ InstrEndParallelQuery(instr, &worker_instr[ParallelWorkerNumber]);
index_close(indexRel, indexLockmode);
table_close(heapRel, heapLockmode);
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 2d7b7cef912..cb238f862a7 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -66,8 +66,7 @@
#define PARALLEL_KEY_TUPLESORT UINT64CONST(0xA000000000000002)
#define PARALLEL_KEY_TUPLESORT_SPOOL2 UINT64CONST(0xA000000000000003)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xA000000000000004)
-#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xA000000000000005)
-#define PARALLEL_KEY_BUFFER_USAGE UINT64CONST(0xA000000000000006)
+#define PARALLEL_KEY_INSTRUMENTATION UINT64CONST(0xA000000000000005)
/*
* DISABLE_LEADER_PARTICIPATION disables the leader's participation in
@@ -195,8 +194,7 @@ typedef struct BTLeader
Sharedsort *sharedsort;
Sharedsort *sharedsort2;
Snapshot snapshot;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
} BTLeader;
/*
@@ -1408,8 +1406,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
Sharedsort *sharedsort2;
BTSpool *btspool = buildstate->spool;
BTLeader *btleader = palloc0_object(BTLeader);
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *instr;
bool leaderparticipates = true;
int querylen;
@@ -1462,18 +1459,14 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
}
/*
- * Estimate space for WalUsage and BufferUsage -- PARALLEL_KEY_WAL_USAGE
- * and PARALLEL_KEY_BUFFER_USAGE.
+ * Estimate space for Instrumentation -- PARALLEL_KEY_INSTRUMENTATION.
*
* If there are no extensions loaded that care, we could skip this. We
* have no way of knowing whether anyone's looking at instrumentation, so
* do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_estimate_keys(&pcxt->estimator, 1);
- shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_KEY_QUERY_TEXT space */
@@ -1560,15 +1553,12 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
}
/*
- * Allocate space for each worker's WalUsage and BufferUsage; no need to
+ * Allocate space for each worker's Instrumentation; no need to
* initialize.
*/
- walusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage);
- bufferusage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufferusage);
+ instr = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_INSTRUMENTATION, instr);
/* Launch workers, saving status for leader/caller */
LaunchParallelWorkers(pcxt);
@@ -1580,8 +1570,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
btleader->sharedsort = sharedsort;
btleader->sharedsort2 = sharedsort2;
btleader->snapshot = snapshot;
- btleader->walusage = walusage;
- btleader->bufferusage = bufferusage;
+ btleader->instr = instr;
/* If no workers were successfully launched, back out (do serial build) */
if (pcxt->nworkers_launched == 0)
@@ -1620,7 +1609,7 @@ _bt_end_parallel(BTLeader *btleader)
* or we might get incomplete data.)
*/
for (i = 0; i < btleader->pcxt->nworkers_launched; i++)
- InstrAccumParallelQuery(&btleader->bufferusage[i], &btleader->walusage[i]);
+ InstrAccumParallelQuery(&btleader->instr[i]);
/* Free last reference to MVCC snapshot, if one was used */
if (IsMVCCSnapshot(btleader->snapshot))
@@ -1754,8 +1743,7 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
QueryInstrumentation *instr;
- WalUsage *walusage;
- BufferUsage *bufferusage;
+ Instrumentation *worker_instr;
int sortmem;
#ifdef BTREE_BUILD_STATS
@@ -1837,11 +1825,8 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
sharedsort2, sortmem, false);
/* Report WAL/buffer usage during parallel execution */
- bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(instr,
- &bufferusage[ParallelWorkerNumber],
- &walusage[ParallelWorkerNumber]);
+ worker_instr = shm_toc_lookup(toc, PARALLEL_KEY_INSTRUMENTATION, false);
+ InstrEndParallelQuery(instr, &worker_instr[ParallelWorkerNumber]);
#ifdef BTREE_BUILD_STATS
if (log_btree_build_stats)
diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index c330c891c03..b5fed54fb85 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -47,9 +47,8 @@
*/
#define PARALLEL_VACUUM_KEY_SHARED 1
#define PARALLEL_VACUUM_KEY_QUERY_TEXT 2
-#define PARALLEL_VACUUM_KEY_BUFFER_USAGE 3
-#define PARALLEL_VACUUM_KEY_WAL_USAGE 4
-#define PARALLEL_VACUUM_KEY_INDEX_STATS 5
+#define PARALLEL_VACUUM_KEY_INSTRUMENTATION 3
+#define PARALLEL_VACUUM_KEY_INDEX_STATS 4
/*
* Shared information among parallel workers. So this is allocated in the DSM
@@ -188,11 +187,8 @@ struct ParallelVacuumState
/* Shared dead items space among parallel vacuum workers */
TidStore *dead_items;
- /* Points to buffer usage area in DSM */
- BufferUsage *buffer_usage;
-
- /* Points to WAL usage area in DSM */
- WalUsage *wal_usage;
+ /* Points to instrumentation area in DSM */
+ Instrumentation *instr;
/*
* False if the index is totally unsuitable target for all parallel
@@ -250,8 +246,7 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int nindexes,
PVShared *shared;
TidStore *dead_items;
PVIndStats *indstats;
- BufferUsage *buffer_usage;
- WalUsage *wal_usage;
+ Instrumentation *instr;
bool *will_parallel_vacuum;
Size est_indstats_len;
Size est_shared_len;
@@ -304,18 +299,15 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int nindexes,
shm_toc_estimate_keys(&pcxt->estimator, 1);
/*
- * Estimate space for BufferUsage and WalUsage --
- * PARALLEL_VACUUM_KEY_BUFFER_USAGE and PARALLEL_VACUUM_KEY_WAL_USAGE.
+ * Estimate space for Instrumentation --
+ * PARALLEL_VACUUM_KEY_INSTRUMENTATION.
*
* If there are no extensions loaded that care, we could skip this. We
* have no way of knowing whether anyone's looking at instrumentation, so
* do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_estimate_keys(&pcxt->estimator, 1);
- shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_VACUUM_KEY_QUERY_TEXT space */
@@ -396,17 +388,13 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int nindexes,
pvs->shared = shared;
/*
- * Allocate space for each worker's BufferUsage and WalUsage; no need to
- * initialize
+ * Allocate space for each worker's Instrumentation; no need to
+ * initialize.
*/
- buffer_usage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, buffer_usage);
- pvs->buffer_usage = buffer_usage;
- wal_usage = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_WAL_USAGE, wal_usage);
- pvs->wal_usage = wal_usage;
+ instr = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_INSTRUMENTATION, instr);
+ pvs->instr = instr;
/* Store query string for workers */
if (debug_query_string)
@@ -749,7 +737,7 @@ parallel_vacuum_process_all_indexes(ParallelVacuumState *pvs, int num_index_scan
WaitForParallelWorkersToFinish(pvs->pcxt);
for (int i = 0; i < pvs->pcxt->nworkers_launched; i++)
- InstrAccumParallelQuery(&pvs->buffer_usage[i], &pvs->wal_usage[i]);
+ InstrAccumParallelQuery(&pvs->instr[i]);
}
/*
@@ -1007,8 +995,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
PVShared *shared;
TidStore *dead_items;
QueryInstrumentation *instr;
- BufferUsage *buffer_usage;
- WalUsage *wal_usage;
+ Instrumentation *worker_instr;
int nindexes;
char *sharedquery;
ErrorContextCallback errcallback;
@@ -1102,11 +1089,8 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
parallel_vacuum_process_safe_indexes(&pvs);
/* Report buffer/WAL usage during parallel execution */
- buffer_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, false);
- wal_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(instr,
- &buffer_usage[ParallelWorkerNumber],
- &wal_usage[ParallelWorkerNumber]);
+ worker_instr = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_INSTRUMENTATION, false);
+ InstrEndParallelQuery(instr, &worker_instr[ParallelWorkerNumber]);
/* Report any remaining cost-based vacuum delay time */
if (track_cost_delay_timing)
diff --git a/src/backend/executor/execParallel.c b/src/backend/executor/execParallel.c
index a99e37c98e2..c09d51428a6 100644
--- a/src/backend/executor/execParallel.c
+++ b/src/backend/executor/execParallel.c
@@ -60,13 +60,12 @@
#define PARALLEL_KEY_EXECUTOR_FIXED UINT64CONST(0xE000000000000001)
#define PARALLEL_KEY_PLANNEDSTMT UINT64CONST(0xE000000000000002)
#define PARALLEL_KEY_PARAMLISTINFO UINT64CONST(0xE000000000000003)
-#define PARALLEL_KEY_BUFFER_USAGE UINT64CONST(0xE000000000000004)
+#define PARALLEL_KEY_INSTRUMENTATION UINT64CONST(0xE000000000000004)
#define PARALLEL_KEY_TUPLE_QUEUE UINT64CONST(0xE000000000000005)
-#define PARALLEL_KEY_INSTRUMENTATION UINT64CONST(0xE000000000000006)
+#define PARALLEL_KEY_NODE_INSTRUMENTATION UINT64CONST(0xE000000000000006)
#define PARALLEL_KEY_DSA UINT64CONST(0xE000000000000007)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xE000000000000008)
#define PARALLEL_KEY_JIT_INSTRUMENTATION UINT64CONST(0xE000000000000009)
-#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xE00000000000000A)
#define PARALLEL_TUPLE_QUEUE_SIZE 65536
@@ -631,8 +630,6 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
char *pstmt_data;
char *pstmt_space;
char *paramlistinfo_space;
- BufferUsage *bufusage_space;
- WalUsage *walusage_space;
SharedExecutorInstrumentation *instrumentation = NULL;
SharedJitInstrumentation *jit_instrumentation = NULL;
int pstmt_len;
@@ -696,21 +693,14 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
shm_toc_estimate_keys(&pcxt->estimator, 1);
/*
- * Estimate space for BufferUsage.
+ * Estimate space for Instrumentation.
*
* If EXPLAIN is not in use and there are no extensions loaded that care,
* we could skip this. But we have no way of knowing whether anyone's
* looking at instrumentation, so do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_estimate_keys(&pcxt->estimator, 1);
-
- /*
- * Same thing for WalUsage.
- */
- shm_toc_estimate_chunk(&pcxt->estimator,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Estimate space for tuple queues. */
@@ -796,17 +786,18 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
shm_toc_insert(pcxt->toc, PARALLEL_KEY_PARAMLISTINFO, paramlistinfo_space);
SerializeParamList(estate->es_param_list_info, ¶mlistinfo_space);
- /* Allocate space for each worker's BufferUsage; no need to initialize. */
- bufusage_space = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(BufferUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufusage_space);
- pei->buffer_usage = bufusage_space;
+ /*
+ * Allocate space for each worker's Instrumentation; no need to
+ * initialize.
+ */
+ {
+ Instrumentation *instr;
- /* Same for WalUsage. */
- walusage_space = shm_toc_allocate(pcxt->toc,
- mul_size(sizeof(WalUsage), pcxt->nworkers));
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage_space);
- pei->wal_usage = walusage_space;
+ instr = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(Instrumentation), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_INSTRUMENTATION, instr);
+ pei->instrumentation = instr;
+ }
/* Set up the tuple queues that the workers will write into. */
pei->tqueue = ExecParallelSetupTupleQueues(pcxt, false);
@@ -832,9 +823,9 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
instrument = GetInstrumentationArray(instrumentation);
for (i = 0; i < nworkers * e.nnodes; ++i)
InstrInitNode(&instrument[i], estate->es_instrument, false);
- shm_toc_insert(pcxt->toc, PARALLEL_KEY_INSTRUMENTATION,
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_NODE_INSTRUMENTATION,
instrumentation);
- pei->instrumentation = instrumentation;
+ pei->node_instrumentation = instrumentation;
if (estate->es_jit_flags != PGJIT_NONE)
{
@@ -1236,7 +1227,7 @@ ExecParallelFinish(ParallelExecutorInfo *pei)
* finish, or we might get incomplete data.)
*/
for (i = 0; i < nworkers; i++)
- InstrAccumParallelQuery(&pei->buffer_usage[i], &pei->wal_usage[i]);
+ InstrAccumParallelQuery(&pei->instrumentation[i]);
pei->finished = true;
}
@@ -1250,11 +1241,11 @@ ExecParallelFinish(ParallelExecutorInfo *pei)
void
ExecParallelCleanup(ParallelExecutorInfo *pei)
{
- /* Accumulate instrumentation, if any. */
- if (pei->instrumentation)
+ /* Accumulate node instrumentation, if any. */
+ if (pei->node_instrumentation)
{
ExecParallelRetrieveInstrumentation(pei->planstate,
- pei->instrumentation);
+ pei->node_instrumentation);
ExecFinalizeWorkerInstrumentation(pei->planstate);
}
@@ -1481,8 +1472,6 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
{
FixedParallelExecutorState *fpes;
QueryInstrumentation *instr;
- BufferUsage *buffer_usage;
- WalUsage *wal_usage;
DestReceiver *receiver;
QueryDesc *queryDesc;
SharedExecutorInstrumentation *instrumentation;
@@ -1497,7 +1486,7 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
/* Set up DestReceiver, SharedExecutorInstrumentation, and QueryDesc. */
receiver = ExecParallelGetReceiver(seg, toc);
- instrumentation = shm_toc_lookup(toc, PARALLEL_KEY_INSTRUMENTATION, true);
+ instrumentation = shm_toc_lookup(toc, PARALLEL_KEY_NODE_INSTRUMENTATION, true);
if (instrumentation != NULL)
instrument_options = instrumentation->instrument_options;
jit_instrumentation = shm_toc_lookup(toc, PARALLEL_KEY_JIT_INSTRUMENTATION,
@@ -1555,11 +1544,12 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
ExecutorFinish(queryDesc);
/* Report buffer/WAL usage during parallel execution. */
- buffer_usage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- wal_usage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(instr,
- &buffer_usage[ParallelWorkerNumber],
- &wal_usage[ParallelWorkerNumber]);
+ {
+ Instrumentation *worker_instr;
+
+ worker_instr = shm_toc_lookup(toc, PARALLEL_KEY_INSTRUMENTATION, false);
+ InstrEndParallelQuery(instr, &worker_instr[ParallelWorkerNumber]);
+ }
/* Report instrumentation data if any instrumentation options are set. */
if (instrumentation != NULL)
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index b84c552c6f8..cfedbad0eba 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -345,11 +345,12 @@ InstrStartParallelQuery(void)
/* report usage after parallel executor shutdown */
void
-InstrEndParallelQuery(QueryInstrumentation *qinstr, BufferUsage *bufusage, WalUsage *walusage)
+InstrEndParallelQuery(QueryInstrumentation *qinstr, Instrumentation *dst)
{
InstrQueryStopFinalize(qinstr);
- memcpy(bufusage, &qinstr->instr.bufusage, sizeof(BufferUsage));
- memcpy(walusage, &qinstr->instr.walusage, sizeof(WalUsage));
+ dst->need_stack = qinstr->instr.need_stack;
+ memcpy(&dst->bufusage, &qinstr->instr.bufusage, sizeof(BufferUsage));
+ memcpy(&dst->walusage, &qinstr->instr.walusage, sizeof(WalUsage));
}
/*
@@ -365,12 +366,11 @@ InstrEndParallelQuery(QueryInstrumentation *qinstr, BufferUsage *bufusage, WalUs
* activity is accumulated.
*/
void
-InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
+InstrAccumParallelQuery(Instrumentation *instr)
{
- BufferUsageAdd(&instr_stack.current->bufusage, bufusage);
- WalUsageAdd(&instr_stack.current->walusage, walusage);
+ InstrAccumStack(instr_stack.current, instr);
- WalUsageAdd(&pgWalUsage, walusage);
+ WalUsageAdd(&pgWalUsage, &instr->walusage);
}
/* Node instrumentation handling */
diff --git a/src/include/executor/execParallel.h b/src/include/executor/execParallel.h
index 5a2034811d5..6c8b602d07f 100644
--- a/src/include/executor/execParallel.h
+++ b/src/include/executor/execParallel.h
@@ -25,9 +25,8 @@ typedef struct ParallelExecutorInfo
{
PlanState *planstate; /* plan subtree we're running in parallel */
ParallelContext *pcxt; /* parallel context we're using */
- BufferUsage *buffer_usage; /* points to bufusage area in DSM */
- WalUsage *wal_usage; /* walusage area in DSM */
- SharedExecutorInstrumentation *instrumentation; /* optional */
+ Instrumentation *instrumentation; /* instrumentation area in DSM */
+ SharedExecutorInstrumentation *node_instrumentation; /* optional */
struct SharedJitInstrumentation *jit_instrumentation; /* optional */
dsa_area *area; /* points to DSA area in DSM */
dsa_pointer param_exec; /* serialized PARAM_EXEC parameters */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index f5cc6fb662b..5bb698d686d 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -286,8 +286,8 @@ extern void InstrQueryStopFinalize(QueryInstrumentation *instr);
extern void InstrQueryRememberChild(QueryInstrumentation *parent, Instrumentation *instr);
pg_nodiscard extern QueryInstrumentation *InstrStartParallelQuery(void);
-extern void InstrEndParallelQuery(QueryInstrumentation *qinstr, BufferUsage *bufusage, WalUsage *walusage);
-extern void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
+extern void InstrEndParallelQuery(QueryInstrumentation *qinstr, Instrumentation *dst);
+extern void InstrAccumParallelQuery(Instrumentation *instr);
extern NodeInstrumentation *InstrAllocNode(QueryInstrumentation *qinstr,
int instrument_options,
--
2.47.1
[application/octet-stream] v15-0008-Index-scans-Show-table-buffer-accesses-separatel.patch (22.9K, 9-v15-0008-Index-scans-Show-table-buffer-accesses-separatel.patch)
download | inline diff:
From 9a352d49e19f5614aedc9511527b92bee3c6a38c Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sat, 7 Mar 2026 11:46:19 -0800
Subject: [PATCH v15 8/9] Index scans: Show table buffer accesses separately in
EXPLAIN ANALYZE
This sets up a separate instrumentation stack that is used whilst an
Index Scan or Index Only Scan does scanning on the table, for example due
to additional data being needed.
EXPLAIN ANALYZE will now show "Table Buffers" that represent such activity.
The activity is also included in regular "Buffers" together with index
activity and that of any child nodes.
Author: Lukas Fittl <[email protected]>
Suggested-by: Andres Freund <[email protected]>
Reviewed-by: Zsolt Parragi <[email protected]>
Reviewed-by: Tomas Vondra <[email protected]>
Discussion: https://www.postgresql.org/message-id/flat/CAP53PkxrmpECzVFpeeEEHDGe6u625s%2BYkmVv5-gw3L_NDSfbiA%40mail.gmail.com#cb583a08e8e096aa1f093bb178906173
Actually populate I(O)S table stack pre index prefetching merge
---
doc/src/sgml/perform.sgml | 13 ++-
doc/src/sgml/ref/explain.sgml | 1 +
src/backend/commands/explain.c | 47 ++++++--
src/backend/executor/execProcnode.c | 46 ++++++++
src/backend/executor/nodeBitmapIndexscan.c | 2 +-
src/backend/executor/nodeIndexonlyscan.c | 41 ++++++-
src/backend/executor/nodeIndexscan.c | 127 +++++++++++++++++----
src/include/executor/instrument_node.h | 5 +
8 files changed, 244 insertions(+), 38 deletions(-)
diff --git a/doc/src/sgml/perform.sgml b/doc/src/sgml/perform.sgml
index 604e8578a8d..d28f4f22535 100644
--- a/doc/src/sgml/perform.sgml
+++ b/doc/src/sgml/perform.sgml
@@ -734,6 +734,7 @@ WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
-> Index Scan using tenk2_unique2 on tenk2 t2 (cost=0.29..7.90 rows=1 width=244) (actual time=0.003..0.003 rows=1.00 loops=10)
Index Cond: (unique2 = t1.unique2)
Index Searches: 10
+ Table Buffers: shared hit=10
Buffers: shared hit=24 read=6
Planning:
Buffers: shared hit=15 dirtied=9
@@ -1005,7 +1006,8 @@ EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
Index Cond: (f1 @> '((0.5,2))'::polygon)
Rows Removed by Index Recheck: 1
Index Searches: 1
- Buffers: shared hit=1
+ Table Buffers: shared hit=1
+ Buffers: shared hit=2
Planning Time: 0.039 ms
Execution Time: 0.098 ms
</screen>
@@ -1014,7 +1016,9 @@ EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
then rejected by a recheck of the index condition. This happens because a
GiST index is <quote>lossy</quote> for polygon containment tests: it actually
returns the rows with polygons that overlap the target, and then we have
- to do the exact containment test on those rows.
+ to do the exact containment test on those rows. The <literal>Table Buffers</literal>
+ counts indicate how many operations were performed on the table instead of
+ the index. This number is included in the <literal>Buffers</literal> counts.
</para>
<para>
@@ -1203,13 +1207,14 @@ EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE unique1 < 100 AND unique2 > 9000
QUERY PLAN
-------------------------------------------------------------------&zwsp;------------------------------------------------------------
Limit (cost=0.29..14.33 rows=2 width=244) (actual time=0.051..0.071 rows=2.00 loops=1)
- Buffers: shared hit=16
+ Buffers: shared hit=14
-> Index Scan using tenk1_unique2 on tenk1 (cost=0.29..70.50 rows=10 width=244) (actual time=0.051..0.070 rows=2.00 loops=1)
Index Cond: (unique2 > 9000)
Filter: (unique1 < 100)
Rows Removed by Filter: 287
Index Searches: 1
- Buffers: shared hit=16
+ Table Buffers: shared hit=11
+ Buffers: shared hit=14
Planning Time: 0.077 ms
Execution Time: 0.086 ms
</screen>
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 5b8b521802e..71070736acb 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -509,6 +509,7 @@ EXPLAIN ANALYZE EXECUTE query(100, 200);
-> Index Scan using test_pkey on test (cost=0.29..10.27 rows=99 width=8) (actual time=0.009..0.025 rows=99.00 loops=1)
Index Cond: ((id > 100) AND (id < 200))
Index Searches: 1
+ Table Buffers: shared hit=1
Buffers: shared hit=4
Planning Time: 0.244 ms
Execution Time: 0.073 ms
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index c93e4cbee97..e5ed2524904 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -144,7 +144,7 @@ static void show_instrumentation_count(const char *qlabel, int which,
static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
static const char *explain_get_index_name(Oid indexId);
static bool peek_buffer_usage(ExplainState *es, const BufferUsage *usage);
-static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
+static void show_buffer_usage(ExplainState *es, const BufferUsage *usage, const char *title);
static void show_wal_usage(ExplainState *es, const WalUsage *usage);
static void show_memory_counters(ExplainState *es,
const MemoryContextCounters *mem_counters);
@@ -611,7 +611,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
}
if (bufusage)
- show_buffer_usage(es, bufusage);
+ show_buffer_usage(es, bufusage, NULL);
if (mem_counters)
show_memory_counters(es, mem_counters);
@@ -1028,7 +1028,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
if (es->buffers && peek_buffer_usage(es, &metrics->instr.bufusage))
{
es->indent++;
- show_buffer_usage(es, &metrics->instr.bufusage);
+ show_buffer_usage(es, &metrics->instr.bufusage, NULL);
es->indent--;
}
}
@@ -1042,7 +1042,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
BYTES_TO_KILOBYTES(metrics->bytesSent), es);
ExplainPropertyText("Format", format, es);
if (es->buffers)
- show_buffer_usage(es, &metrics->instr.bufusage);
+ show_buffer_usage(es, &metrics->instr.bufusage, NULL);
}
ExplainCloseGroup("Serialization", "Serialization", true, es);
@@ -1972,6 +1972,9 @@ ExplainNode(PlanState *planstate, List *ancestors,
show_instrumentation_count("Rows Removed by Filter", 1,
planstate, es);
show_indexsearches_info(planstate, es);
+
+ if (es->buffers && planstate->instrument)
+ show_buffer_usage(es, &((IndexScanState *) planstate)->iss_Instrument->table_instr.bufusage, "Table");
break;
case T_IndexOnlyScan:
show_scan_qual(((IndexOnlyScan *) plan)->indexqual,
@@ -1989,6 +1992,9 @@ ExplainNode(PlanState *planstate, List *ancestors,
ExplainPropertyFloat("Heap Fetches", NULL,
planstate->instrument->ntuples2, 0, es);
show_indexsearches_info(planstate, es);
+
+ if (es->buffers && planstate->instrument)
+ show_buffer_usage(es, &((IndexOnlyScanState *) planstate)->ioss_Instrument->table_instr.bufusage, "Table");
break;
case T_BitmapIndexScan:
show_scan_qual(((BitmapIndexScan *) plan)->indexqualorig,
@@ -2290,7 +2296,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
/* Show buffer/WAL usage */
if (es->buffers && planstate->instrument)
- show_buffer_usage(es, &planstate->instrument->instr.bufusage);
+ show_buffer_usage(es, &planstate->instrument->instr.bufusage, NULL);
if (es->wal && planstate->instrument)
show_wal_usage(es, &planstate->instrument->instr.walusage);
@@ -2309,7 +2315,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
ExplainOpenWorker(n, es);
if (es->buffers)
- show_buffer_usage(es, &instrument->instr.bufusage);
+ show_buffer_usage(es, &instrument->instr.bufusage, NULL);
if (es->wal)
show_wal_usage(es, &instrument->instr.walusage);
ExplainCloseWorker(n, es);
@@ -4109,7 +4115,7 @@ peek_buffer_usage(ExplainState *es, const BufferUsage *usage)
* Show buffer usage details. This better be sync with peek_buffer_usage.
*/
static void
-show_buffer_usage(ExplainState *es, const BufferUsage *usage)
+show_buffer_usage(ExplainState *es, const BufferUsage *usage, const char *title)
{
if (es->format == EXPLAIN_FORMAT_TEXT)
{
@@ -4134,6 +4140,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
if (has_shared || has_local || has_temp)
{
ExplainIndentText(es);
+ if (title)
+ appendStringInfo(es->str, "%s ", title);
appendStringInfoString(es->str, "Buffers:");
if (has_shared)
@@ -4189,6 +4197,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
if (has_shared_timing || has_local_timing || has_temp_timing)
{
ExplainIndentText(es);
+ if (title)
+ appendStringInfo(es->str, "%s ", title);
appendStringInfoString(es->str, "I/O Timings:");
if (has_shared_timing)
@@ -4230,6 +4240,14 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
else
{
+ char *buffers_title = NULL;
+
+ if (title)
+ {
+ buffers_title = psprintf("%s Buffers", title);
+ ExplainOpenGroup(buffers_title, buffers_title, true, es);
+ }
+
ExplainPropertyInteger("Shared Hit Blocks", NULL,
usage->shared_blks_hit, es);
ExplainPropertyInteger("Shared Read Blocks", NULL,
@@ -4250,8 +4268,20 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
usage->temp_blks_read, es);
ExplainPropertyInteger("Temp Written Blocks", NULL,
usage->temp_blks_written, es);
+
+ if (buffers_title)
+ ExplainCloseGroup(buffers_title, buffers_title, true, es);
+
if (track_io_timing)
{
+ char *timings_title = NULL;
+
+ if (title)
+ {
+ timings_title = psprintf("%s I/O Timings", title);
+ ExplainOpenGroup(timings_title, timings_title, true, es);
+ }
+
ExplainPropertyFloat("Shared I/O Read Time", "ms",
INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time),
3, es);
@@ -4270,6 +4300,9 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
ExplainPropertyFloat("Temp I/O Write Time", "ms",
INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time),
3, es);
+
+ if (timings_title)
+ ExplainCloseGroup(timings_title, timings_title, true, es);
}
}
}
diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c
index ac400670fea..28f1f666a3b 100644
--- a/src/backend/executor/execProcnode.c
+++ b/src/backend/executor/execProcnode.c
@@ -847,6 +847,20 @@ ExecFinalizeNodeInstrumentation_walker(PlanState *node, void *context)
planstate_tree_walker(node, ExecFinalizeNodeInstrumentation_walker,
&node->instrument->instr);
+ /* IndexScan/IndexOnlyScan have a separate entry to track table access */
+ if (IsA(node, IndexScanState))
+ {
+ IndexScanState *iss = castNode(IndexScanState, node);
+
+ InstrFinalizeChild(&iss->iss_Instrument->table_instr, &node->instrument->instr);
+ }
+ else if (IsA(node, IndexOnlyScanState))
+ {
+ IndexOnlyScanState *ioss = castNode(IndexOnlyScanState, node);
+
+ InstrFinalizeChild(&ioss->ioss_Instrument->table_instr, &node->instrument->instr);
+ }
+
InstrFinalizeChild(&node->instrument->instr, parent);
return false;
@@ -892,6 +906,38 @@ ExecFinalizeWorkerInstrumentation_walker(PlanState *node, void *context)
num_workers = node->worker_instrument->num_workers;
+ /*
+ * Fold per-worker IndexScan/IndexOnlyScan table buffer stats into the
+ * per-worker node stats, matching what ExecFinalizeNodeInstrumentation
+ * does for the leader.
+ */
+ if (IsA(node, IndexScanState))
+ {
+ IndexScanState *iss = castNode(IndexScanState, node);
+
+ if (iss->iss_SharedInfo)
+ {
+ int nworkers = Min(num_workers, iss->iss_SharedInfo->num_workers);
+
+ for (int n = 0; n < nworkers; n++)
+ InstrAccumStack(&node->worker_instrument->instrument[n].instr,
+ &iss->iss_SharedInfo->winstrument[n].table_instr);
+ }
+ }
+ else if (IsA(node, IndexOnlyScanState))
+ {
+ IndexOnlyScanState *ioss = castNode(IndexOnlyScanState, node);
+
+ if (ioss->ioss_SharedInfo)
+ {
+ int nworkers = Min(num_workers, ioss->ioss_SharedInfo->num_workers);
+
+ for (int n = 0; n < nworkers; n++)
+ InstrAccumStack(&node->worker_instrument->instrument[n].instr,
+ &ioss->ioss_SharedInfo->winstrument[n].table_instr);
+ }
+ }
+
/* Accumulate this node's per-worker stats to parent's per-worker stats */
if (parent && parent->worker_instrument)
{
diff --git a/src/backend/executor/nodeBitmapIndexscan.c b/src/backend/executor/nodeBitmapIndexscan.c
index 70c55ee6d61..657ee2d0667 100644
--- a/src/backend/executor/nodeBitmapIndexscan.c
+++ b/src/backend/executor/nodeBitmapIndexscan.c
@@ -276,7 +276,7 @@ ExecInitBitmapIndexScan(BitmapIndexScan *node, EState *estate, int eflags)
/* Set up instrumentation of bitmap index scans if requested */
if (estate->es_instrument)
- indexstate->biss_Instrument = palloc0_object(IndexScanInstrumentation);
+ indexstate->biss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
diff --git a/src/backend/executor/nodeIndexonlyscan.c b/src/backend/executor/nodeIndexonlyscan.c
index de6154fd541..d918570e684 100644
--- a/src/backend/executor/nodeIndexonlyscan.c
+++ b/src/backend/executor/nodeIndexonlyscan.c
@@ -67,6 +67,7 @@ IndexOnlyNext(IndexOnlyScanState *node)
IndexScanDesc scandesc;
TupleTableSlot *slot;
ItemPointer tid;
+ Instrumentation *table_instr = NULL;
/*
* extract necessary information from index scan node
@@ -83,6 +84,9 @@ IndexOnlyNext(IndexOnlyScanState *node)
econtext = node->ss.ps.ps_ExprContext;
slot = node->ss.ss_ScanTupleSlot;
+ if (node->ioss_Instrument && node->ioss_Instrument->table_instr.need_stack)
+ table_instr = &node->ioss_Instrument->table_instr;
+
if (scandesc == NULL)
{
/*
@@ -165,11 +169,22 @@ IndexOnlyNext(IndexOnlyScanState *node)
ItemPointerGetBlockNumber(tid),
&node->ioss_VMBuffer))
{
+ bool found;
+
/*
* Rats, we have to visit the heap to check visibility.
*/
InstrCountTuples2(node, 1);
- if (!index_fetch_heap(scandesc, node->ioss_TableSlot))
+
+ if (table_instr)
+ InstrPushStack(table_instr);
+
+ found = index_fetch_heap(scandesc, node->ioss_TableSlot);
+
+ if (table_instr)
+ InstrPopStack(table_instr);
+
+ if (!found)
continue; /* no visible tuple, try next index entry */
ExecClearTuple(node->ioss_TableSlot);
@@ -436,6 +451,7 @@ ExecEndIndexOnlyScan(IndexOnlyScanState *node)
* which will have a new IndexOnlyScanState and zeroed stats.
*/
winstrument->nsearches += node->ioss_Instrument->nsearches;
+ InstrAccumStack(&winstrument->table_instr, &node->ioss_Instrument->table_instr);
}
/*
@@ -610,7 +626,21 @@ ExecInitIndexOnlyScan(IndexOnlyScan *node, EState *estate, int eflags)
/* Set up instrumentation of index-only scans if requested */
if (estate->es_instrument)
- indexstate->ioss_Instrument = palloc0_object(IndexScanInstrumentation);
+ {
+ indexstate->ioss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
+
+ /*
+ * Track table and index access separately. We intentionally don't
+ * collect timing (even if enabled), since we don't need it, and
+ * IndexOnlyNext calls InstrPushStack / InstrPopStack (instead of the
+ * full InstrNode*) to reduce overhead.
+ */
+ if ((estate->es_instrument & INSTRUMENT_BUFFERS) != 0)
+ {
+ InstrInitOptions(&indexstate->ioss_Instrument->table_instr, INSTRUMENT_BUFFERS);
+ InstrQueryRememberChild(estate->es_query_instr, &indexstate->ioss_Instrument->table_instr);
+ }
+ }
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
@@ -899,4 +929,11 @@ ExecIndexOnlyScanRetrieveInstrumentation(IndexOnlyScanState *node)
SharedInfo->num_workers * sizeof(IndexScanInstrumentation);
node->ioss_SharedInfo = palloc(size);
memcpy(node->ioss_SharedInfo, SharedInfo, size);
+
+ /* Aggregate workers' table buffer/WAL usage into leader's entry */
+ for (int i = 0; i < node->ioss_SharedInfo->num_workers; i++)
+ {
+ InstrAccumStack(&node->ioss_Instrument->table_instr,
+ &node->ioss_SharedInfo->winstrument[i].table_instr);
+ }
}
diff --git a/src/backend/executor/nodeIndexscan.c b/src/backend/executor/nodeIndexscan.c
index 1620d146071..5041266984a 100644
--- a/src/backend/executor/nodeIndexscan.c
+++ b/src/backend/executor/nodeIndexscan.c
@@ -85,7 +85,10 @@ IndexNext(IndexScanState *node)
ExprContext *econtext;
ScanDirection direction;
IndexScanDesc scandesc;
+ ItemPointer tid;
TupleTableSlot *slot;
+ bool found;
+ Instrumentation *table_instr = NULL;
/*
* extract necessary information from index scan node
@@ -102,6 +105,9 @@ IndexNext(IndexScanState *node)
econtext = node->ss.ps.ps_ExprContext;
slot = node->ss.ss_ScanTupleSlot;
+ if (node->iss_Instrument && node->iss_Instrument->table_instr.need_stack)
+ table_instr = &node->iss_Instrument->table_instr;
+
if (scandesc == NULL)
{
/*
@@ -132,8 +138,24 @@ IndexNext(IndexScanState *node)
/*
* ok, now that we have what we need, fetch the next tuple.
*/
- while (index_getnext_slot(scandesc, direction, slot))
+ while ((tid = index_getnext_tid(scandesc, direction)) != NULL)
{
+ if (table_instr)
+ InstrPushStack(table_instr);
+
+ for (;;)
+ {
+ found = index_fetch_heap(scandesc, slot);
+ if (found || !scandesc->xs_heap_continue)
+ break;
+ }
+
+ if (table_instr)
+ InstrPopStack(table_instr);
+
+ if (unlikely(!found))
+ continue;
+
CHECK_FOR_INTERRUPTS();
/*
@@ -181,6 +203,7 @@ IndexNextWithReorder(IndexScanState *node)
Datum *lastfetched_vals;
bool *lastfetched_nulls;
int cmp;
+ Instrumentation *table_instr = NULL;
estate = node->ss.ps.state;
@@ -200,6 +223,9 @@ IndexNextWithReorder(IndexScanState *node)
econtext = node->ss.ps.ps_ExprContext;
slot = node->ss.ss_ScanTupleSlot;
+ if (node->iss_Instrument && node->iss_Instrument->table_instr.need_stack)
+ table_instr = &node->iss_Instrument->table_instr;
+
if (scandesc == NULL)
{
/*
@@ -263,36 +289,67 @@ IndexNextWithReorder(IndexScanState *node)
}
/*
- * Fetch next tuple from the index.
+ * Fetch next valid tuple from the index.
*/
-next_indextuple:
- if (!index_getnext_slot(scandesc, ForwardScanDirection, slot))
+ for (;;)
{
+ ItemPointer tid;
+ bool found;
+
+ /* Time to fetch the next TID from the index */
+ tid = index_getnext_tid(scandesc, ForwardScanDirection);
+
+ /* If we're out of index entries, we're done */
+ if (tid == NULL)
+ {
+ /*
+ * No more tuples from the index. But we still need to drain
+ * any remaining tuples from the queue before we're done.
+ */
+ node->iss_ReachedEnd = true;
+ break;
+ }
+
+ Assert(ItemPointerEquals(tid, &scandesc->xs_heaptid));
+
+ if (table_instr)
+ InstrPushStack(table_instr);
+
+ for (;;)
+ {
+ found = index_fetch_heap(scandesc, slot);
+ if (found || !scandesc->xs_heap_continue)
+ break;
+ }
+
+ if (table_instr)
+ InstrPopStack(table_instr);
+
/*
- * No more tuples from the index. But we still need to drain any
- * remaining tuples from the queue before we're done.
+ * If the index was lossy, we have to recheck the index quals and
+ * ORDER BY expressions using the fetched tuple.
*/
- node->iss_ReachedEnd = true;
- continue;
- }
-
- /*
- * If the index was lossy, we have to recheck the index quals and
- * ORDER BY expressions using the fetched tuple.
- */
- if (scandesc->xs_recheck)
- {
- econtext->ecxt_scantuple = slot;
- if (!ExecQualAndReset(node->indexqualorig, econtext))
+ if (found && scandesc->xs_recheck)
{
- /* Fails recheck, so drop it and loop back for another */
- InstrCountFiltered2(node, 1);
- /* allow this loop to be cancellable */
- CHECK_FOR_INTERRUPTS();
- goto next_indextuple;
+ econtext->ecxt_scantuple = slot;
+ if (!ExecQualAndReset(node->indexqualorig, econtext))
+ {
+ /* Fails recheck, so drop it and loop back for another */
+ InstrCountFiltered2(node, 1);
+ /* allow this loop to be cancellable */
+ CHECK_FOR_INTERRUPTS();
+ continue;
+ }
}
+
+ if (found)
+ break;
}
+ /* No more index entries, re-run to clear the reorder queue */
+ if (node->iss_ReachedEnd)
+ continue;
+
if (scandesc->xs_recheckorderby)
{
econtext->ecxt_scantuple = slot;
@@ -818,6 +875,7 @@ ExecEndIndexScan(IndexScanState *node)
* which will have a new IndexOnlyScanState and zeroed stats.
*/
winstrument->nsearches += node->iss_Instrument->nsearches;
+ InstrAccumStack(&winstrument->table_instr, &node->iss_Instrument->table_instr);
}
/*
@@ -980,7 +1038,21 @@ ExecInitIndexScan(IndexScan *node, EState *estate, int eflags)
/* Set up instrumentation of index scans if requested */
if (estate->es_instrument)
- indexstate->iss_Instrument = palloc0_object(IndexScanInstrumentation);
+ {
+ indexstate->iss_Instrument = MemoryContextAllocZero(estate->es_query_instr->instr_cxt, sizeof(IndexScanInstrumentation));
+
+ /*
+ * Track table and index access separately. We intentionally don't
+ * collect timing (even if enabled), since we don't need it, and
+ * IndexNext / IndexNextWithReorder call InstrPushStack /
+ * InstrPopStack (instead of the full InstrNode*) to reduce overhead.
+ */
+ if ((estate->es_instrument & INSTRUMENT_BUFFERS) != 0)
+ {
+ InstrInitOptions(&indexstate->iss_Instrument->table_instr, INSTRUMENT_BUFFERS);
+ InstrQueryRememberChild(estate->es_query_instr, &indexstate->iss_Instrument->table_instr);
+ }
+ }
/* Open the index relation. */
lockmode = exec_rt_fetch(node->scan.scanrelid, estate)->rellockmode;
@@ -1834,4 +1906,11 @@ ExecIndexScanRetrieveInstrumentation(IndexScanState *node)
SharedInfo->num_workers * sizeof(IndexScanInstrumentation);
node->iss_SharedInfo = palloc(size);
memcpy(node->iss_SharedInfo, SharedInfo, size);
+
+ /* Aggregate workers' table buffer/WAL usage into leader's entry */
+ for (int i = 0; i < node->iss_SharedInfo->num_workers; i++)
+ {
+ InstrAccumStack(&node->iss_Instrument->table_instr,
+ &node->iss_SharedInfo->winstrument[i].table_instr);
+ }
}
diff --git a/src/include/executor/instrument_node.h b/src/include/executor/instrument_node.h
index 2a0ff377a73..e2315cef384 100644
--- a/src/include/executor/instrument_node.h
+++ b/src/include/executor/instrument_node.h
@@ -18,6 +18,8 @@
#ifndef INSTRUMENT_NODE_H
#define INSTRUMENT_NODE_H
+#include "executor/instrument.h"
+
/* ---------------------
* Instrumentation information for aggregate function execution
@@ -48,6 +50,9 @@ typedef struct IndexScanInstrumentation
{
/* Index search count (incremented with pgstat_count_index_scan call) */
uint64 nsearches;
+
+ /* Instrumentation utilized for tracking buffer usage during table access */
+ Instrumentation table_instr;
} IndexScanInstrumentation;
/*
--
2.47.1
[application/octet-stream] v15-0005-Optimize-measuring-WAL-buffer-usage-through-stac.patch (81.2K, 10-v15-0005-Optimize-measuring-WAL-buffer-usage-through-stac.patch)
download | inline diff:
From bf8c303c85a6da53e4735b4271a0648a8f2a54d6 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Mon, 6 Apr 2026 01:20:45 -0700
Subject: [PATCH v15 5/9] Optimize measuring WAL/buffer usage through
stack-based instrumentation
Previously, in order to determine the buffer/WAL usage of a given code
section, we utilized continuously incrementing global counters that get
updated when the actual activity (e.g. shared block read) occurred, and
then calculated a diff when the code section ended. This resulted in a
bottleneck for executor node instrumentation specifically, with the
function BufferUsageAccumDiff showing up in profiles and in some cases
adding up to 10% overhead to an EXPLAIN (ANALYZE, BUFFERS) run.
Instead, introduce a stack-based mechanism, where the actual activity
writes into the current stack entry. In the case of executor nodes, this
means that each node gets its own stack entry that is pushed at
InstrStartNode, and popped at InstrEndNode. Stack entries are zero
initialized (avoiding the diff mechanism) and get added to their parent
entry when they are finalized, i.e. no more modifications can occur.
To correctly handle abort situations, any use of instrumentation stacks
must involve either a top-level QueryInstrumentation struct, and its
associated InstrQueryStart/InstrQueryStop helpers (which use resource
owners to handle aborts), or the Instrumentation struct itself with
dedicated PG_TRY/PG_FINALLY calls that ensure the stack is in a
consistent state after an abort.
In tests, the stack-based instrumentation mechanism reduces the overhead
of EXPLAIN (ANALYZE, BUFFERS ON, TIMING OFF) for a large COUNT(*) query
from about 50% to 22% on top of the actual runtime.
This also drops the global pgBufferUsage, any callers interested in
measuring buffer activity should instead utilize InstrStart/InstrStop.
The related global pgWalUsage is kept for now due to its use in pgstat
to track aggregate WAL activity and heap_page_prune_and_freeze for
measuring FPIs.
Author: Lukas Fittl <[email protected]>
Reviewed-by: Zsolt Parragi <[email protected]>
Reviewed-by: Heikki Linnakangas <[email protected]>
Discussion: https://www.postgresql.org/message-id/flat/CAP53PkxrmpECzVFpeeEEHDGe6u625s%2BYkmVv5-gw3L_NDSfbiA%40mail.gmail.com#cb583a08e8e096aa1f093bb178906173
---
.../pg_stat_statements/pg_stat_statements.c | 6 +-
src/backend/access/brin/brin.c | 10 +-
src/backend/access/gin/gininsert.c | 10 +-
src/backend/access/heap/vacuumlazy.c | 12 +-
src/backend/access/nbtree/nbtsort.c | 10 +-
src/backend/commands/analyze.c | 12 +-
src/backend/commands/explain.c | 10 +-
src/backend/commands/explain_dr.c | 2 +
src/backend/commands/prepare.c | 10 +-
src/backend/commands/tablecmds.c | 5 +-
src/backend/commands/vacuumparallel.c | 10 +-
src/backend/executor/README.instrument | 237 ++++++++++
src/backend/executor/execMain.c | 94 +++-
src/backend/executor/execParallel.c | 32 +-
src/backend/executor/execPartition.c | 5 +-
src/backend/executor/execProcnode.c | 106 ++++-
src/backend/executor/execUtils.c | 13 +-
src/backend/executor/instrument.c | 429 ++++++++++++++----
src/backend/replication/logical/worker.c | 2 +-
src/backend/storage/buffer/bufmgr.c | 6 +-
src/backend/utils/activity/pgstat_io.c | 6 +-
src/include/executor/executor.h | 6 +-
src/include/executor/instrument.h | 199 +++++++-
src/include/nodes/execnodes.h | 2 +
src/include/utils/resowner.h | 1 +
src/tools/pgindent/typedefs.list | 2 +
26 files changed, 1044 insertions(+), 193 deletions(-)
create mode 100644 src/backend/executor/README.instrument
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 346adb5599f..4fdd5ef8898 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -929,12 +929,11 @@ pgss_planner(Query *parse,
}
PG_FINALLY();
{
+ InstrStopFinalize(&instr);
nesting_level--;
}
PG_END_TRY();
- InstrStop(&instr);
-
pgss_store(query_string,
parse->queryId,
parse->stmt_location,
@@ -1145,6 +1144,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
}
PG_FINALLY();
{
+ InstrStopFinalize(&instr);
nesting_level--;
}
PG_END_TRY();
@@ -1159,8 +1159,6 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
* former value, which'd otherwise be a good idea.
*/
- InstrStop(&instr);
-
/*
* Track the total number of rows retrieved or affected by the utility
* statements of COPY, FETCH, CREATE TABLE AS, CREATE MATERIALIZED
diff --git a/src/backend/access/brin/brin.c b/src/backend/access/brin/brin.c
index bdb30752e09..3a5176c76c7 100644
--- a/src/backend/access/brin/brin.c
+++ b/src/backend/access/brin/brin.c
@@ -2434,8 +2434,8 @@ _brin_begin_parallel(BrinBuildState *buildstate, Relation heap, Relation index,
* and PARALLEL_KEY_BUFFER_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgWalUsage or
- * pgBufferUsage, so do it unconditionally.
+ * have no way of knowing whether anyone's looking at instrumentation, so
+ * do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(WalUsage), pcxt->nworkers));
@@ -2887,6 +2887,7 @@ _brin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
Relation indexRel;
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
+ QueryInstrumentation *instr;
WalUsage *walusage;
BufferUsage *bufferusage;
int sortmem;
@@ -2936,7 +2937,7 @@ _brin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
tuplesort_attach_shared(sharedsort, seg);
/* Prepare to track buffer usage during parallel execution */
- InstrStartParallelQuery();
+ instr = InstrStartParallelQuery();
/*
* Might as well use reliable figure when doling out maintenance_work_mem
@@ -2951,7 +2952,8 @@ _brin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
/* Report WAL/buffer usage during parallel execution */
bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(&bufferusage[ParallelWorkerNumber],
+ InstrEndParallelQuery(instr,
+ &bufferusage[ParallelWorkerNumber],
&walusage[ParallelWorkerNumber]);
index_close(indexRel, indexLockmode);
diff --git a/src/backend/access/gin/gininsert.c b/src/backend/access/gin/gininsert.c
index 9d83a495775..0d80f72a0b0 100644
--- a/src/backend/access/gin/gininsert.c
+++ b/src/backend/access/gin/gininsert.c
@@ -991,8 +991,8 @@ _gin_begin_parallel(GinBuildState *buildstate, Relation heap, Relation index,
* and PARALLEL_KEY_BUFFER_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgWalUsage or
- * pgBufferUsage, so do it unconditionally.
+ * have no way of knowing whether anyone's looking at instrumentation, so
+ * do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(WalUsage), pcxt->nworkers));
@@ -2118,6 +2118,7 @@ _gin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
Relation indexRel;
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
+ QueryInstrumentation *instr;
WalUsage *walusage;
BufferUsage *bufferusage;
int sortmem;
@@ -2186,7 +2187,7 @@ _gin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
tuplesort_attach_shared(sharedsort, seg);
/* Prepare to track buffer usage during parallel execution */
- InstrStartParallelQuery();
+ instr = InstrStartParallelQuery();
/*
* Might as well use reliable figure when doling out maintenance_work_mem
@@ -2201,7 +2202,8 @@ _gin_parallel_build_main(dsm_segment *seg, shm_toc *toc)
/* Report WAL/buffer usage during parallel execution */
bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(&bufferusage[ParallelWorkerNumber],
+ InstrEndParallelQuery(instr,
+ &bufferusage[ParallelWorkerNumber],
&walusage[ParallelWorkerNumber]);
index_close(indexRel, indexLockmode);
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 30f589c9207..291d9d67bc2 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -637,7 +637,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
TimestampTz starttime = 0;
PgStat_Counter startreadtime = 0,
startwritetime = 0;
- Instrumentation *instr = NULL;
+ QueryInstrumentation *instr = NULL;
ErrorContextCallback errcallback;
char **indnames = NULL;
Size dead_items_max_bytes = 0;
@@ -653,8 +653,8 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
startreadtime = pgStatBlockReadTime;
startwritetime = pgStatBlockWriteTime;
}
- instr = InstrAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
- InstrStart(instr);
+ instr = InstrQueryAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
+ InstrQueryStart(instr);
}
/* Used for instrumentation and stats report */
@@ -985,7 +985,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
{
TimestampTz endtime = GetCurrentTimestamp();
- InstrStop(instr);
+ InstrQueryStopFinalize(instr);
if (verbose || params->log_vacuum_min_duration == 0 ||
TimestampDifferenceExceeds(starttime, endtime,
@@ -1001,8 +1001,8 @@ heap_vacuum_rel(Relation rel, const VacuumParams *params,
int64 total_blks_hit;
int64 total_blks_read;
int64 total_blks_dirtied;
- BufferUsage bufferusage = instr->bufusage;
- WalUsage walusage = instr->walusage;
+ BufferUsage bufferusage = instr->instr.bufusage;
+ WalUsage walusage = instr->instr.walusage;
TimestampDifference(starttime, endtime, &secs_dur, &usecs_dur);
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 756dfa3dcf4..2d7b7cef912 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -1466,8 +1466,8 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
* and PARALLEL_KEY_BUFFER_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgWalUsage or
- * pgBufferUsage, so do it unconditionally.
+ * have no way of knowing whether anyone's looking at instrumentation, so
+ * do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(WalUsage), pcxt->nworkers));
@@ -1753,6 +1753,7 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
Relation indexRel;
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
+ QueryInstrumentation *instr;
WalUsage *walusage;
BufferUsage *bufferusage;
int sortmem;
@@ -1828,7 +1829,7 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
}
/* Prepare to track buffer usage during parallel execution */
- InstrStartParallelQuery();
+ instr = InstrStartParallelQuery();
/* Perform sorting of spool, and possibly a spool2 */
sortmem = maintenance_work_mem / btshared->scantuplesortstates;
@@ -1838,7 +1839,8 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
/* Report WAL/buffer usage during parallel execution */
bufferusage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(&bufferusage[ParallelWorkerNumber],
+ InstrEndParallelQuery(instr,
+ &bufferusage[ParallelWorkerNumber],
&walusage[ParallelWorkerNumber]);
#ifdef BTREE_BUILD_STATS
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index 8472fc0c280..10f8a2dc81c 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -309,7 +309,7 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
Oid save_userid;
int save_sec_context;
int save_nestlevel;
- Instrumentation *instr = NULL;
+ QueryInstrumentation *instr = NULL;
PgStat_Counter startreadtime = 0;
PgStat_Counter startwritetime = 0;
@@ -361,8 +361,8 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
pg_rusage_init(&ru0);
- instr = InstrAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
- InstrStart(instr);
+ instr = InstrQueryAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
+ InstrQueryStart(instr);
}
/* Used for instrumentation and stats report */
@@ -743,7 +743,7 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
{
TimestampTz endtime = GetCurrentTimestamp();
- InstrStop(instr);
+ InstrQueryStopFinalize(instr);
if (verbose || params->log_analyze_min_duration == 0 ||
TimestampDifferenceExceeds(starttime, endtime,
@@ -757,8 +757,8 @@ do_analyze_rel(Relation onerel, const VacuumParams *params,
int64 total_blks_hit;
int64 total_blks_read;
int64 total_blks_dirtied;
- BufferUsage bufusage = instr->bufusage;
- WalUsage walusage = instr->walusage;
+ BufferUsage bufusage = instr->instr.bufusage;
+ WalUsage walusage = instr->instr.walusage;
total_blks_hit = bufusage.shared_blks_hit +
bufusage.local_blks_hit;
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index d6dc7268438..c93e4cbee97 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -324,7 +324,7 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
QueryEnvironment *queryEnv)
{
PlannedStmt *plan;
- Instrumentation plan_instr = {0};
+ QueryInstrumentation *plan_instr = NULL;
int instrument_options = INSTRUMENT_TIMER;
MemoryContextCounters mem_counters;
MemoryContext planner_ctx = NULL;
@@ -333,7 +333,7 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
if (es->buffers)
instrument_options |= INSTRUMENT_BUFFERS;
- InstrInitOptions(&plan_instr, instrument_options);
+ plan_instr = InstrQueryAlloc(instrument_options);
if (es->memory)
{
@@ -351,12 +351,12 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
saved_ctx = MemoryContextSwitchTo(planner_ctx);
}
- InstrStart(&plan_instr);
+ InstrQueryStart(plan_instr);
/* plan the query */
plan = pg_plan_query(query, queryString, cursorOptions, params, es);
- InstrStop(&plan_instr);
+ InstrQueryStopFinalize(plan_instr);
if (es->memory)
{
@@ -366,7 +366,7 @@ standard_ExplainOneQuery(Query *query, int cursorOptions,
/* run it (if needed) and produce output */
ExplainOnePlan(plan, into, es, queryString, params, queryEnv,
- &plan_instr.total, (es->buffers ? &plan_instr.bufusage : NULL),
+ &plan_instr->instr.total, (es->buffers ? &plan_instr->instr.bufusage : NULL),
es->memory ? &mem_counters : NULL);
}
diff --git a/src/backend/commands/explain_dr.c b/src/backend/commands/explain_dr.c
index df5ae5f4569..836395d6992 100644
--- a/src/backend/commands/explain_dr.c
+++ b/src/backend/commands/explain_dr.c
@@ -236,6 +236,8 @@ serializeAnalyzeShutdown(DestReceiver *self)
{
SerializeDestReceiver *receiver = (SerializeDestReceiver *) self;
+ InstrFinalizeChild(&receiver->metrics.instr, instr_stack.current);
+
if (receiver->finfos)
pfree(receiver->finfos);
receiver->finfos = NULL;
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index bf9f2eb6149..ee811357588 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -581,7 +581,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
ListCell *p;
ParamListInfo paramLI = NULL;
EState *estate = NULL;
- Instrumentation plan_instr = {0};
+ QueryInstrumentation *plan_instr = NULL;
int instrument_options = INSTRUMENT_TIMER;
MemoryContextCounters mem_counters;
MemoryContext planner_ctx = NULL;
@@ -590,7 +590,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
if (es->buffers)
instrument_options |= INSTRUMENT_BUFFERS;
- InstrInitOptions(&plan_instr, instrument_options);
+ plan_instr = InstrQueryAlloc(instrument_options);
if (es->memory)
{
@@ -602,7 +602,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
saved_ctx = MemoryContextSwitchTo(planner_ctx);
}
- InstrStart(&plan_instr);
+ InstrQueryStart(plan_instr);
/* Look it up in the hash table */
entry = FetchPreparedStatement(execstmt->name, true);
@@ -637,7 +637,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
cplan = GetCachedPlan(entry->plansource, paramLI,
CurrentResourceOwner, pstate->p_queryEnv);
- InstrStop(&plan_instr);
+ InstrQueryStopFinalize(plan_instr);
if (es->memory)
{
@@ -654,7 +654,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
if (pstmt->commandType != CMD_UTILITY)
ExplainOnePlan(pstmt, into, es, query_string, paramLI, pstate->p_queryEnv,
- &plan_instr.total, (es->buffers ? &plan_instr.bufusage : NULL),
+ &plan_instr->instr.total, (es->buffers ? &plan_instr->instr.bufusage : NULL),
es->memory ? &mem_counters : NULL);
else
ExplainOneUtility(pstmt->utilityStmt, into, es, pstate, paramLI);
diff --git a/src/backend/commands/tablecmds.c b/src/backend/commands/tablecmds.c
index 0ce2e81f9c2..9fea019c39e 100644
--- a/src/backend/commands/tablecmds.c
+++ b/src/backend/commands/tablecmds.c
@@ -2139,7 +2139,7 @@ ExecuteTruncateGuts(List *explicit_rels,
rel,
0, /* dummy rangetable index */
NULL,
- 0);
+ 0, NULL);
estate->es_opened_result_relations =
lappend(estate->es_opened_result_relations, resultRelInfo);
resultRelInfo++;
@@ -6337,7 +6337,8 @@ ATRewriteTable(AlteredTableInfo *tab, Oid OIDNewHeap)
oldrel,
0, /* dummy rangetable index */
NULL,
- estate->es_instrument);
+ estate->es_instrument,
+ estate->es_query_instr);
MemoryContextSwitchTo(oldcontext);
}
diff --git a/src/backend/commands/vacuumparallel.c b/src/backend/commands/vacuumparallel.c
index 77834b96a21..c330c891c03 100644
--- a/src/backend/commands/vacuumparallel.c
+++ b/src/backend/commands/vacuumparallel.c
@@ -308,8 +308,8 @@ parallel_vacuum_init(Relation rel, Relation *indrels, int nindexes,
* PARALLEL_VACUUM_KEY_BUFFER_USAGE and PARALLEL_VACUUM_KEY_WAL_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgBufferUsage or
- * pgWalUsage, so do it unconditionally.
+ * have no way of knowing whether anyone's looking at instrumentation, so
+ * do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
@@ -1006,6 +1006,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
PVIndStats *indstats;
PVShared *shared;
TidStore *dead_items;
+ QueryInstrumentation *instr;
BufferUsage *buffer_usage;
WalUsage *wal_usage;
int nindexes;
@@ -1095,7 +1096,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
error_context_stack = &errcallback;
/* Prepare to track buffer usage during parallel execution */
- InstrStartParallelQuery();
+ instr = InstrStartParallelQuery();
/* Process indexes to perform vacuum/cleanup */
parallel_vacuum_process_safe_indexes(&pvs);
@@ -1103,7 +1104,8 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
/* Report buffer/WAL usage during parallel execution */
buffer_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, false);
wal_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ InstrEndParallelQuery(instr,
+ &buffer_usage[ParallelWorkerNumber],
&wal_usage[ParallelWorkerNumber]);
/* Report any remaining cost-based vacuum delay time */
diff --git a/src/backend/executor/README.instrument b/src/backend/executor/README.instrument
new file mode 100644
index 00000000000..7df837dbc77
--- /dev/null
+++ b/src/backend/executor/README.instrument
@@ -0,0 +1,237 @@
+src/backend/executor/README.instrument
+
+Instrumentation
+===============
+
+The instrumentation subsystem measures time, buffer usage and WAL activity
+during query execution and other similar activities. It is used by
+EXPLAIN ANALYZE, pg_stat_statements, and other consumers that need
+activity and/or timing metrics over a section of code.
+
+The design has two central goals:
+
+* Make it cheap to measure activity in a section of code, even when
+ that section is called many times and the aggregate is what is used
+ (as is the case with per-node instrumentation in the executor)
+
+* Ensure nested instrumentation accurately measures activity/timing,
+ even when execution is aborted due to errors being thrown.
+
+The key data structures are defined in src/include/executor/instrument.h
+and the implementation lives in src/backend/executor/instrument.c.
+
+
+Instrumentation Options
+-----------------------
+
+Callers specify what to measure with a bitmask of InstrumentOption flags:
+
+ INSTRUMENT_ROWS -- row counts only (used with NodeInstrumentation)
+ INSTRUMENT_TIMER -- wall-clock timing and row counts
+ INSTRUMENT_BUFFERS -- buffer hit/read/dirtied/written counts and I/O time
+ INSTRUMENT_WAL -- WAL records, FPI, bytes
+
+INSTRUMENT_BUFFERS and INSTRUMENT_WAL utilize the instrumentation stack
+(described below) for efficient handling of counter values.
+
+
+Struct Hierarchy
+----------------
+
+There are the following instrumentation structs, each specialized for a
+different scope:
+
+Instrumentation Base struct. Holds timing and buffer/WAL counters.
+
+QueryInstrumentation Extends Instrumentation for query-level tracking. When
+ stack-based tracking is enabled, it owns a dedicated
+ MemoryContext and uses the ResourceOwner mechanism for
+ abort cleanup.
+
+NodeInstrumentation Extends Instrumentation for per-plan-node statistics
+ (startup time, tuple counts, loop counts, etc).
+
+TriggerInstrumentation Extends Instrumentation with a firing count.
+
+
+Stack-based instrumentation
+===========================
+
+For tracking WAL or buffer usage counters, the specialized stack-based
+instrumentation is used.
+
+A simple approach to measuring buffer/WAL activity in a code section could be
+to have a set of global counters, snapshot all the counters at the start, and
+diff them at the end. But, this is expensive in practice: BufferUsage alone
+has many fields, and the diff must be computed for every InstrStartNode /
+InstrStopNode cycle.
+
+An alternative is to write counter updates directly into the struct that
+should receive them, avoiding the diff. But that has two complexities: Low-level
+code such as the buffer manager, has no direct pointers to higher level
+structs, such as plan nodes tracking buffer usage. And instrumentation is often
+nested: We might both be interested in the aggregate buffer usage of a query, and
+the individual per-node details. Stack-based instrumentation solves for that:
+
+At all times, there is a stack that tracks which Instrumentation is currently
+active. The stack is represented by instr_stack, a per-backend global
+that holds a dynamic array of Instrumentation pointers. The field
+instr_stack.current always points to the current stack entry that should
+be updated when activity occurs. When the stack array is empty, the
+current stack points to instr_top.
+
+For example, if a backend has two portals open, the overall nesting of
+Instrumentation and their respective InstrStart/InstrStop calls creates a
+tree-like structure like this:
+
+ Session (instr_top)
+ |
+ +-- Query A (QueryInstrumentation)
+ | |
+ | +-- NestLoop (NodeInstrumentation)
+ | |
+ | +-- Seq Scan A (NodeInstrumentation)
+ | +-- Seq Scan B (NodeInstrumentation)
+ |
+ +-- Query B (QueryInstrumentation)
+ |
+ +-- Seq Scan C (NodeInstrumentation)
+
+While executing Seq Scan B, the stack looks like:
+
+ instr_top (implicit bottom, not in the entries array)
+ 0: Query A
+ 1: NestLoop
+ 2: Seq Scan B <-- instr_stack.current
+
+When no query is running, the stack is empty (stack_size == 0) and
+instr_stack.current points to instr_top.
+
+Any buffer or WAL counter update (via the INSTR_BUFUSAGE_* and
+INSTR_WALUSAGE_* macros in the buffer manager, WAL insertion code, etc.)
+writes directly into instr_stack.current. Each instrumentation node starts
+zeroed, so the values it accumulates while on top of the stack represent
+exactly the activity that occurred during that time.
+
+Every Instrumentation node (except for instr_top) has a target, or parent, it
+will be accumulated into, which is typically the Instrumentation that was the
+current stack entry when it was created.
+
+For example, when Seq Scan A gets finalized in regular execution via ExecutorFinish,
+its instrumentation data gets added to the immediate parent in
+the execution tree, the NestLoop, which will then get added to Query A's
+QueryInstrumentation, which then accumulates to the parent.
+
+While we can typically think of this as a tree, the NodeInstrumentation
+underneath a particular QueryInstrumentation could behave differently --
+for example, it could propagate directly to the QueryInstrumentation, in
+order to not show cumulative numbers in EXPLAIN ANALYZE.
+
+Note these relationships are partially implicit, especially when it comes
+to NodeInstrumentation. Each QueryInstrumentation maintains a list of its
+unfinalized child nodes. The parent of a QueryInstrumentation itself is
+determined by the stack (see below): when a query is finalized or cleaned
+up on abort, its counters are accumulated to whatever entry is then current
+on the stack, which is typically instr_top.
+
+
+Finalization and Abort Safety
+=============================
+
+Finalization is the process of rolling up a node's buffer/WAL counters to
+its parent. In normal execution, nodes are pushed onto the stack when they
+start and popped when they stop; at finalization time their accumulated
+counters are added to the parent.
+
+Due to the use of longjmp for error handling, functions can exit abruptly
+without executing their normal cleanup code. On abort, two things need
+to happen:
+
+1. The stack is reset to the level saved at the start of the aborting
+ (sub-)transaction level. This ensures that we don't later try to update
+ counters on a freed stack entry. We also need to ensure that the stack
+ entry that was current before a particular Instrumentation started, is
+ current again after it stops.
+
+2. Finalize all affected Instrumentation nodes, rolling up their counters
+ to the innermost surviving Instrumentation, so that data is not lost.
+
+For example, if Seq Scan B aborts while the stack is:
+
+ instr_top (implicit bottom)
+ 0: Query A
+ 1: NestLoop
+ 2: Seq Scan B
+
+The abort handler for Query A accumulates all unfinalized children (Seq
+Scan A, Seq Scan B, NestLoop) directly into Query A's counters, then
+unwinds the instrumentation stack and accumulates Query A's counters to
+instr_top.
+
+Note that on abort the children do not accumulate through each other (Seq
+Scan B -> NestLoop -> Query A); they all accumulate directly to their
+parent QueryInstrumentation. This means the order in which children are
+released does not matter -- this is important because ResourceOwner cleanup
+does not guarantee a particular release order. The per-node breakdown is lost,
+but the instrumentation active when the query was started (instr_top in the
+above example) survives the abort, and its counters include the activity.
+
+If multiple QueryInstrumentations are active on the stack (e.g. nested
+portals), the abort handler of each uses InstrStopFinalize() to accumulate
+the statistics to the parent entry of either the entry being released, or a
+previously released entry if it was higher up in the stack, so they compose
+correctly regardless of release order.
+
+There are two mechanisms for achieving abort safety:
+
+* Resource Owner (QueryInstrumentation): registers with the current
+ ResourceOwner at start. On transaction abort, the resource owner system
+ calls the release callback, which walks unfinalized child entries,
+ accumulates their data, unwinds the stack, and destroys the dedicated
+ memory context (freeing the QueryInstrumentation and all child
+ allocations as a unit). This is the recommended approach when the
+ instrumented code already has an appropriate resource owner (e.g. it
+ runs inside a portal). The query executor uses this path.
+
+* PG_FINALLY (base Instrumentation): when no suitable resource owner
+ exists, or when the caller wants to inspect the instrumentation data
+ even after an error, the base Instrumentation can be used with a
+ PG_TRY/PG_FINALLY block that calls InstrStopFinalize().
+
+Both mechanisms add overhead, so neither is suitable for high-frequency
+instrumentation like per-node measurements in the executor. Instead,
+plan node and trigger children rely on their parent QueryInstrumentation
+for abort safety: they are allocated in the parent's memory context and
+registered in its unfinalized-entries list, so the parent's abort handler
+recovers their data automatically. In normal execution, children are
+finalized explicitly by the caller.
+
+Parallel Query
+--------------
+
+Parallel workers get their own QueryInstrumentation so they can measure
+buffer and WAL activity independently, then copy the totals into dynamic
+shared memory at worker shutdown. The leader accumulates these into its
+own stack.
+
+When per-node instrumentation is active, parallel workers skip per-node
+finalization at shutdown to avoid double-counting; the per-node data is
+aggregated separately through InstrAggNode().
+
+
+Memory Handling
+===============
+
+Instrumentation objects that use the stack must survive until finalization
+runs, including the abort case. To ensure this, QueryInstrumentation
+creates a dedicated "Instrumentation" MemoryContext (instr_cxt) as a child
+of TopMemoryContext. All child instrumentation (nodes, triggers) should be
+allocated in this context.
+
+On successful completion, instr_cxt is reparented to CurrentMemoryContext
+so its lifetime is tied to the caller's context. On abort, the
+ResourceOwner cleanup frees it after accumulating the instrumentation data
+to the current stack entry after resetting the stack.
+
+When the stack is not needed (timer/rows only), Instrumentation allocations
+happen in CurrentMemoryContext instead of TopMemoryContext.
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 7d74f6da402..44d4fea76eb 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -78,6 +78,7 @@ ExecutorCheckPerms_hook_type ExecutorCheckPerms_hook = NULL;
/* decls for local routines only used within this module */
static void InitPlan(QueryDesc *queryDesc, int eflags);
static void CheckValidRowMarkRel(Relation rel, RowMarkType markType);
+static void ExecFinalizeTriggerInstrumentation(EState *estate);
static void ExecPostprocessPlan(EState *estate);
static void ExecEndPlan(PlanState *planstate, EState *estate);
static void ExecutePlan(QueryDesc *queryDesc,
@@ -254,10 +255,18 @@ standard_ExecutorStart(QueryDesc *queryDesc, int eflags)
* Set up query-level instrumentation if extensions have requested it via
* totaltime_options. Ensure an extension has not allocated totaltime
* itself.
+ *
+ * Alternatively, also set it up when running EXPLAIN (ANALYZE), as we
+ * utilize totaltime as the parent for node and trigger instrumentation.
*/
Assert(queryDesc->totaltime == NULL);
- if (queryDesc->totaltime_options)
- queryDesc->totaltime = InstrQueryAlloc(queryDesc->totaltime_options);
+ if (queryDesc->totaltime_options || queryDesc->instrument_options)
+ {
+ estate->es_query_instr = InstrQueryAlloc(queryDesc->instrument_options |
+ queryDesc->totaltime_options);
+
+ queryDesc->totaltime = &estate->es_query_instr->instr;
+ }
/*
* Set up an AFTER-trigger statement context, unless told not to, or
@@ -340,9 +349,9 @@ standard_ExecutorRun(QueryDesc *queryDesc,
*/
oldcontext = MemoryContextSwitchTo(estate->es_query_cxt);
- /* Allow instrumentation of Executor overall runtime */
- if (queryDesc->totaltime)
- InstrStart(queryDesc->totaltime);
+ /* Start up instrumentation for this execution run */
+ if (estate->es_query_instr)
+ InstrQueryStart(estate->es_query_instr);
/*
* extract information from the query descriptor and the query feature.
@@ -393,8 +402,8 @@ standard_ExecutorRun(QueryDesc *queryDesc,
if (sendTuples)
dest->rShutdown(dest);
- if (queryDesc->totaltime)
- InstrStop(queryDesc->totaltime);
+ if (estate->es_query_instr)
+ InstrQueryStop(estate->es_query_instr);
MemoryContextSwitchTo(oldcontext);
}
@@ -443,8 +452,8 @@ standard_ExecutorFinish(QueryDesc *queryDesc)
oldcontext = MemoryContextSwitchTo(estate->es_query_cxt);
/* Allow instrumentation of Executor overall runtime */
- if (queryDesc->totaltime)
- InstrStart(queryDesc->totaltime);
+ if (estate->es_query_instr)
+ InstrQueryStart(estate->es_query_instr);
/* Run ModifyTable nodes to completion */
ExecPostprocessPlan(estate);
@@ -453,8 +462,29 @@ standard_ExecutorFinish(QueryDesc *queryDesc)
if (!(estate->es_top_eflags & EXEC_FLAG_SKIP_TRIGGERS))
AfterTriggerEndQuery(estate);
- if (queryDesc->totaltime)
- InstrStop(queryDesc->totaltime);
+ if (estate->es_query_instr)
+ {
+ /*
+ * Accumulate per-node and trigger statistics to their respective
+ * parent instrumentation stacks.
+ *
+ * We skip this in parallel workers because their per-node stats are
+ * reported individually via ExecParallelReportInstrumentation, and
+ * the leader's own ExecFinalizeNodeInstrumentation handles
+ * propagation. If we accumulated here, the leader would
+ * double-count: worker parent nodes would already include their
+ * children's stats, and then the leader's accumulation would add the
+ * children again.
+ */
+ if (!IsParallelWorker() && estate->es_instrument)
+ {
+ ExecFinalizeNodeInstrumentation(queryDesc->planstate);
+
+ ExecFinalizeTriggerInstrumentation(estate);
+ }
+
+ InstrQueryStopFinalize(estate->es_query_instr);
+ }
MemoryContextSwitchTo(oldcontext);
@@ -1272,7 +1302,8 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
Relation resultRelationDesc,
Index resultRelationIndex,
ResultRelInfo *partition_root_rri,
- int instrument_options)
+ int instrument_options,
+ QueryInstrumentation *qinstr)
{
MemSet(resultRelInfo, 0, sizeof(ResultRelInfo));
resultRelInfo->type = T_ResultRelInfo;
@@ -1293,8 +1324,8 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
palloc0_array(FmgrInfo, n);
resultRelInfo->ri_TrigWhenExprs = (ExprState **)
palloc0_array(ExprState *, n);
- if (instrument_options)
- resultRelInfo->ri_TrigInstrument = InstrAllocTrigger(n, instrument_options);
+ if (qinstr)
+ resultRelInfo->ri_TrigInstrument = InstrAllocTrigger(qinstr, instrument_options, n);
}
else
{
@@ -1367,6 +1398,10 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
* also provides a way for EXPLAIN ANALYZE to report the runtimes of such
* triggers.) So we make additional ResultRelInfo's as needed, and save them
* in es_trig_target_relations.
+ *
+ * Note: if new relation lists are searched here, they must also be added to
+ * ExecFinalizeTriggerInstrumentation so that trigger instrumentation data
+ * is properly accumulated.
*/
ResultRelInfo *
ExecGetTriggerResultRel(EState *estate, Oid relid,
@@ -1433,7 +1468,8 @@ ExecGetTriggerResultRel(EState *estate, Oid relid,
rel,
0, /* dummy rangetable index */
rootRelInfo,
- estate->es_instrument);
+ estate->es_instrument,
+ estate->es_query_instr);
estate->es_trig_target_relations =
lappend(estate->es_trig_target_relations, rInfo);
MemoryContextSwitchTo(oldcontext);
@@ -1496,7 +1532,8 @@ ExecGetAncestorResultRels(EState *estate, ResultRelInfo *resultRelInfo)
/* dummy rangetable index */
InitResultRelInfo(rInfo, ancRel, 0, NULL,
- estate->es_instrument);
+ estate->es_instrument,
+ estate->es_query_instr);
ancResultRels = lappend(ancResultRels, rInfo);
}
ancResultRels = lappend(ancResultRels, rootRelInfo);
@@ -1509,6 +1546,30 @@ ExecGetAncestorResultRels(EState *estate, ResultRelInfo *resultRelInfo)
return resultRelInfo->ri_ancestorResultRels;
}
+static void
+ExecFinalizeTriggerInstrumentation(EState *estate)
+{
+ List *rels = NIL;
+
+ rels = list_concat(rels, estate->es_tuple_routing_result_relations);
+ rels = list_concat(rels, estate->es_opened_result_relations);
+ rels = list_concat(rels, estate->es_trig_target_relations);
+
+ foreach_node(ResultRelInfo, rInfo, rels)
+ {
+ TriggerInstrumentation *ti = rInfo->ri_TrigInstrument;
+
+ if (ti == NULL || rInfo->ri_TrigDesc == NULL)
+ continue;
+
+ for (int nt = 0; nt < rInfo->ri_TrigDesc->numtriggers; nt++)
+ {
+ if (ti[nt].instr.need_stack)
+ InstrAccumStack(&estate->es_query_instr->instr, &ti[nt].instr);
+ }
+ }
+}
+
/* ----------------------------------------------------------------
* ExecPostprocessPlan
*
@@ -3066,6 +3127,7 @@ EvalPlanQualStart(EPQState *epqstate, Plan *planTree)
/* es_trig_target_relations must NOT be copied */
rcestate->es_top_eflags = parentestate->es_top_eflags;
rcestate->es_instrument = parentestate->es_instrument;
+ rcestate->es_query_instr = parentestate->es_query_instr;
/* es_auxmodifytables must NOT be copied */
/*
diff --git a/src/backend/executor/execParallel.c b/src/backend/executor/execParallel.c
index 5e4a4a9740c..a99e37c98e2 100644
--- a/src/backend/executor/execParallel.c
+++ b/src/backend/executor/execParallel.c
@@ -700,7 +700,7 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
*
* If EXPLAIN is not in use and there are no extensions loaded that care,
* we could skip this. But we have no way of knowing whether anyone's
- * looking at pgBufferUsage, so do it unconditionally.
+ * looking at instrumentation, so do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
@@ -1081,14 +1081,28 @@ ExecParallelRetrieveInstrumentation(PlanState *planstate,
instrument = GetInstrumentationArray(instrumentation);
instrument += i * instrumentation->num_workers;
for (n = 0; n < instrumentation->num_workers; ++n)
+ {
InstrAggNode(planstate->instrument, &instrument[n]);
+ /*
+ * Also add worker WAL usage to the global pgWalUsage counter.
+ *
+ * When per-node instrumentation is active, parallel workers skip
+ * ExecFinalizeNodeInstrumentation (to avoid double-counting in
+ * EXPLAIN), so per-node WAL activity is not rolled up into the
+ * query-level stats that InstrAccumParallelQuery receives. Without
+ * this, pgWalUsage would under-report WAL generated by parallel
+ * workers when instrumentation is active.
+ */
+ WalUsageAdd(&pgWalUsage, &instrument[n].instr.walusage);
+ }
+
/*
* Also store the per-worker detail.
*
- * Worker instrumentation should be allocated in the same context as the
- * regular instrumentation information, which is the per-query context.
- * Switch into per-query memory context.
+ * Ensure worker instrumentation is allocated in the per-query context. We
+ * don't need to place this in the instrumentation context since no more
+ * stack-based instrumentation work is being done.
*/
oldcontext = MemoryContextSwitchTo(planstate->state->es_query_cxt);
ibytes = mul_size(instrumentation->num_workers, sizeof(NodeInstrumentation));
@@ -1238,9 +1252,13 @@ ExecParallelCleanup(ParallelExecutorInfo *pei)
{
/* Accumulate instrumentation, if any. */
if (pei->instrumentation)
+ {
ExecParallelRetrieveInstrumentation(pei->planstate,
pei->instrumentation);
+ ExecFinalizeWorkerInstrumentation(pei->planstate);
+ }
+
/* Accumulate JIT instrumentation, if any. */
if (pei->jit_instrumentation)
ExecParallelRetrieveJitInstrumentation(pei->planstate,
@@ -1462,6 +1480,7 @@ void
ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
{
FixedParallelExecutorState *fpes;
+ QueryInstrumentation *instr;
BufferUsage *buffer_usage;
WalUsage *wal_usage;
DestReceiver *receiver;
@@ -1522,7 +1541,7 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
* leader, which also doesn't count buffer accesses and WAL activity that
* occur during executor startup.
*/
- InstrStartParallelQuery();
+ instr = InstrStartParallelQuery();
/*
* Run the plan. If we specified a tuple bound, be careful not to demand
@@ -1538,7 +1557,8 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
/* Report buffer/WAL usage during parallel execution. */
buffer_usage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
wal_usage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ InstrEndParallelQuery(instr,
+ &buffer_usage[ParallelWorkerNumber],
&wal_usage[ParallelWorkerNumber]);
/* Report instrumentation data if any instrumentation options are set. */
diff --git a/src/backend/executor/execPartition.c b/src/backend/executor/execPartition.c
index d96d4f9947b..6888fbe4278 100644
--- a/src/backend/executor/execPartition.c
+++ b/src/backend/executor/execPartition.c
@@ -586,7 +586,8 @@ ExecInitPartitionInfo(ModifyTableState *mtstate, EState *estate,
partrel,
0,
rootResultRelInfo,
- estate->es_instrument);
+ estate->es_instrument,
+ estate->es_query_instr);
/*
* Verify result relation is a valid target for an INSERT. An UPDATE of a
@@ -1381,7 +1382,7 @@ ExecInitPartitionDispatchInfo(EState *estate,
{
ResultRelInfo *rri = makeNode(ResultRelInfo);
- InitResultRelInfo(rri, rel, 0, rootResultRelInfo, 0);
+ InitResultRelInfo(rri, rel, 0, rootResultRelInfo, 0, NULL);
proute->nonleaf_partitions[dispatchidx] = rri;
}
else
diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c
index 132fe37ef60..f006931c94d 100644
--- a/src/backend/executor/execProcnode.c
+++ b/src/backend/executor/execProcnode.c
@@ -123,6 +123,8 @@
static TupleTableSlot *ExecProcNodeFirst(PlanState *node);
static TupleTableSlot *ExecProcNodeInstr(PlanState *node);
static bool ExecShutdownNode_walker(PlanState *node, void *context);
+static bool ExecFinalizeNodeInstrumentation_walker(PlanState *node, void *context);
+static bool ExecFinalizeWorkerInstrumentation_walker(PlanState *node, void *context);
/* ------------------------------------------------------------------------
@@ -414,7 +416,8 @@ ExecInitNode(Plan *node, EState *estate, int eflags)
/* Set up instrumentation for this node if requested */
if (estate->es_instrument)
- result->instrument = InstrAllocNode(estate->es_instrument,
+ result->instrument = InstrAllocNode(estate->es_query_instr,
+ estate->es_instrument,
result->async_capable);
return result;
@@ -788,10 +791,10 @@ ExecShutdownNode_walker(PlanState *node, void *context)
* at least once already. We don't expect much CPU consumption during
* node shutdown, but in the case of Gather or Gather Merge, we may shut
* down workers at this stage. If so, their buffer usage will get
- * propagated into pgBufferUsage at this point, and we want to make sure
- * that it gets associated with the Gather node. We skip this if the node
- * has never been executed, so as to avoid incorrectly making it appear
- * that it has.
+ * propagated into the current instrumentation stack entry at this point,
+ * and we want to make sure that it gets associated with the Gather node.
+ * We skip this if the node has never been executed, so as to avoid
+ * incorrectly making it appear that it has.
*/
if (node->instrument && node->instrument->running)
InstrStartNode(node->instrument);
@@ -829,6 +832,99 @@ ExecShutdownNode_walker(PlanState *node, void *context)
return false;
}
+/*
+ * ExecFinalizeNodeInstrumentation
+ *
+ * Accumulate instrumentation stats from all execution nodes to their respective
+ * parents (or the original parent instrumentation).
+ *
+ * This must run after the cleanup done by ExecShutdownNode, and not rely on any
+ * resources cleaned up by it. We also expect shutdown actions to have occurred,
+ * e.g. parallel worker instrumentation to have been added to the leader.
+ */
+void
+ExecFinalizeNodeInstrumentation(PlanState *node)
+{
+ (void) ExecFinalizeNodeInstrumentation_walker(node, instr_stack.current);
+}
+
+static bool
+ExecFinalizeNodeInstrumentation_walker(PlanState *node, void *context)
+{
+ Instrumentation *parent = (Instrumentation *) context;
+
+ Assert(parent != NULL);
+
+ if (node == NULL)
+ return false;
+
+ Assert(node->instrument != NULL);
+
+ /*
+ * Recurse into children first (bottom-up accumulation), and accummulate
+ * to this nodes instrumentation as the parent context.
+ */
+ planstate_tree_walker(node, ExecFinalizeNodeInstrumentation_walker,
+ &node->instrument->instr);
+
+ InstrFinalizeChild(&node->instrument->instr, parent);
+
+ return false;
+}
+
+/*
+ * ExecFinalizeWorkerInstrumentation
+ *
+ * Accumulate per-worker instrumentation stats from child nodes into their
+ * parents, mirroring what ExecFinalizeNodeInstrumentation does for the
+ * leader's own stats. Without this, per-worker buffer/WAL stats shown by
+ * EXPLAIN (ANALYZE, VERBOSE) would only reflect each node's own direct
+ * activity, not including children.
+ *
+ * This must run after ExecParallelRetrieveInstrumentation has populated
+ * worker_instrument for all nodes in the parallel subtree.
+ */
+void
+ExecFinalizeWorkerInstrumentation(PlanState *node)
+{
+ (void) ExecFinalizeWorkerInstrumentation_walker(node, NULL);
+}
+
+static bool
+ExecFinalizeWorkerInstrumentation_walker(PlanState *node, void *context)
+{
+ PlanState *parent = (PlanState *) context;
+ int num_workers;
+
+ if (node == NULL)
+ return false;
+
+ /*
+ * Recurse into children first (bottom-up accumulation), passing this node
+ * as parent context if it has worker_instrument, otherwise pass through
+ * the previous parent.
+ */
+ planstate_tree_walker(node, ExecFinalizeWorkerInstrumentation_walker,
+ node->worker_instrument ? (void *) node : context);
+
+ if (!node->worker_instrument)
+ return false;
+
+ num_workers = node->worker_instrument->num_workers;
+
+ /* Accumulate this node's per-worker stats to parent's per-worker stats */
+ if (parent && parent->worker_instrument)
+ {
+ int parent_workers = parent->worker_instrument->num_workers;
+
+ for (int n = 0; n < Min(num_workers, parent_workers); n++)
+ InstrAccumStack(&parent->worker_instrument->instrument[n].instr,
+ &node->worker_instrument->instrument[n].instr);
+ }
+
+ return false;
+}
+
/*
* ExecSetTupleBound
*
diff --git a/src/backend/executor/execUtils.c b/src/backend/executor/execUtils.c
index 1eb6b9f1f40..8db2b70e5fe 100644
--- a/src/backend/executor/execUtils.c
+++ b/src/backend/executor/execUtils.c
@@ -151,6 +151,7 @@ CreateExecutorState(void)
estate->es_top_eflags = 0;
estate->es_instrument = 0;
+ estate->es_query_instr = NULL;
estate->es_finished = false;
estate->es_exprcontexts = NIL;
@@ -227,6 +228,15 @@ FreeExecutorState(EState *estate)
estate->es_partition_directory = NULL;
}
+ /*
+ * Make sure the instrumentation context gets freed. This usually gets
+ * re-parented under the per-query context in InstrQueryStopFinalize, but
+ * that won't happen during EXPLAIN (BUFFERS) since ExecutorFinish never
+ * gets called, so we would otherwise leak it in TopMemoryContext.
+ */
+ if (estate->es_query_instr && estate->es_query_instr->instr.need_stack)
+ MemoryContextDelete(estate->es_query_instr->instr_cxt);
+
/*
* Free the per-query memory context, thereby releasing all working
* memory, including the EState node itself.
@@ -913,7 +923,8 @@ ExecInitResultRelation(EState *estate, ResultRelInfo *resultRelInfo,
resultRelationDesc,
rti,
NULL,
- estate->es_instrument);
+ estate->es_instrument,
+ estate->es_query_instr);
if (estate->es_result_relations == NULL)
estate->es_result_relations = (ResultRelInfo **)
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 011a9684df0..b84c552c6f8 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -16,31 +16,53 @@
#include <unistd.h>
#include "executor/instrument.h"
+#include "utils/memutils.h"
+#include "utils/resowner.h"
-BufferUsage pgBufferUsage;
-static BufferUsage save_pgBufferUsage;
WalUsage pgWalUsage;
-static WalUsage save_pgWalUsage;
+Instrumentation instr_top;
+InstrStackState instr_stack = {
+ .stack_space = 0,
+ .stack_size = 0,
+ .entries = NULL,
+ .current = &instr_top,
+};
-static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
-static void WalUsageAdd(WalUsage *dst, WalUsage *add);
+void
+InstrStackGrow(void)
+{
+ int space = instr_stack.stack_space;
+
+ Assert(instr_stack.stack_size >= instr_stack.stack_space);
+
+ if (instr_stack.entries == NULL)
+ {
+ space = 10; /* Allocate sufficient initial space for
+ * typical activity */
+ instr_stack.entries = MemoryContextAlloc(TopMemoryContext,
+ sizeof(Instrumentation *) * space);
+ }
+ else
+ {
+ space *= 2;
+ instr_stack.entries = repalloc_array(instr_stack.entries, Instrumentation *, space);
+ }
+ /* Update stack space after allocation succeeded to protect against OOMs */
+ instr_stack.stack_space = space;
+}
/* General purpose instrumentation handling */
-Instrumentation *
-InstrAlloc(int instrument_options)
+static inline bool
+InstrNeedStack(int instrument_options)
{
- Instrumentation *instr = palloc0_object(Instrumentation);
-
- InstrInitOptions(instr, instrument_options);
- return instr;
+ return (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_WAL)) != 0;
}
void
InstrInitOptions(Instrumentation *instr, int instrument_options)
{
- instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
- instr->need_walusage = (instrument_options & INSTRUMENT_WAL) != 0;
+ instr->need_stack = InstrNeedStack(instrument_options);
instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
}
@@ -55,12 +77,8 @@ InstrStart(Instrumentation *instr)
INSTR_TIME_SET_CURRENT(instr->starttime);
}
- /* save buffer usage totals at start, if needed */
- if (instr->need_bufusage)
- instr->bufusage_start = pgBufferUsage;
-
- if (instr->need_walusage)
- instr->walusage_start = pgWalUsage;
+ if (instr->need_stack)
+ InstrPushStack(instr);
}
/*
@@ -84,14 +102,9 @@ InstrStopCommon(Instrumentation *instr, instr_time *accum_time)
INSTR_TIME_SET_ZERO(instr->starttime);
}
- /* Add delta of buffer usage since InstrStart to the totals */
- if (instr->need_bufusage)
- BufferUsageAccumDiff(&instr->bufusage,
- &pgBufferUsage, &instr->bufusage_start);
-
- if (instr->need_walusage)
- WalUsageAccumDiff(&instr->walusage,
- &pgWalUsage, &instr->walusage_start);
+ /* pop the stack, unless InstrStopFinalize previously cleaned up */
+ if (instr->on_stack)
+ InstrPopStack(instr);
}
void
@@ -100,16 +113,279 @@ InstrStop(Instrumentation *instr)
InstrStopCommon(instr, &instr->total);
}
+/*
+ * Stops instrumentation, finalizes the stack entry and accumulates to its parent.
+ *
+ * Note that this intentionally allows passing a stack that is not the current
+ * top, as can happen with PG_FINALLY, or resource owners, which don't have a
+ * guaranteed cleanup order.
+ */
+void
+InstrStopFinalize(Instrumentation *instr)
+{
+ /*
+ * If our current node is on the stack, make sure we reset the stack to
+ * the parent of whichever of the released stack entries has the lowest
+ * index
+ */
+ if (instr->on_stack)
+ {
+ int idx = -1;
+
+ for (int i = instr_stack.stack_size - 1; i >= 0; i--)
+ {
+ if (instr_stack.entries[i] == instr)
+ {
+ idx = i;
+ break;
+ }
+ }
+
+ if (idx < 0)
+ elog(ERROR, "instrumentation entry not found on stack");
+
+ /* Clear on_stack for any intermediate entries we're skipping over */
+ for (int i = instr_stack.stack_size - 1; i > idx; i--)
+ instr_stack.entries[i]->on_stack = false;
+
+ while (instr_stack.stack_size > idx + 1)
+ instr_stack.stack_size--;
+ }
+
+ InstrStop(instr);
+
+ /*
+ * Accumulate all instrumentation to the currently active instrumentation,
+ * so that callers get a complete picture of activity, even after an abort
+ */
+ InstrAccumStack(instr_stack.current, instr);
+}
+
+/*
+ * Finalize child instrumentation by accumulating buffer/WAL usage to the
+ * provided instrumentation, which may be the current entry, or one the caller
+ * treats as a parent and will add to the totals later.
+ *
+ * Also deletes the unfinalized entry to avoid double counting in an abort
+ * situation, e.g. during executor finish.
+ */
+void
+InstrFinalizeChild(Instrumentation *instr, Instrumentation *parent)
+{
+ if (instr->need_stack)
+ {
+ if (!dlist_node_is_detached(&instr->unfinalized_entry))
+ dlist_delete_thoroughly(&instr->unfinalized_entry);
+
+ InstrAccumStack(parent, instr);
+ }
+}
+
+
+/* Query instrumentation handling */
+
+/*
+ * Use ResourceOwner mechanism to correctly reset instr_stack on abort.
+ */
+static void ResOwnerReleaseInstrumentation(Datum res);
+static const ResourceOwnerDesc instrumentation_resowner_desc =
+{
+ .name = "instrumentation",
+ .release_phase = RESOURCE_RELEASE_AFTER_LOCKS,
+ .release_priority = RELEASE_PRIO_INSTRUMENTATION,
+ .ReleaseResource = ResOwnerReleaseInstrumentation,
+ .DebugPrint = NULL, /* default message is fine */
+};
+
+static inline void
+ResourceOwnerRememberInstrumentation(ResourceOwner owner, QueryInstrumentation *qinstr)
+{
+ ResourceOwnerRemember(owner, PointerGetDatum(qinstr), &instrumentation_resowner_desc);
+}
+
+static inline void
+ResourceOwnerForgetInstrumentation(ResourceOwner owner, QueryInstrumentation *qinstr)
+{
+ ResourceOwnerForget(owner, PointerGetDatum(qinstr), &instrumentation_resowner_desc);
+}
+
+static void
+ResOwnerReleaseInstrumentation(Datum res)
+{
+ QueryInstrumentation *qinstr = (QueryInstrumentation *) DatumGetPointer(res);
+ MemoryContext instr_cxt = qinstr->instr_cxt;
+ dlist_mutable_iter iter;
+
+ /* Accumulate data from all unfinalized child entries (nodes, triggers) */
+ dlist_foreach_modify(iter, &qinstr->unfinalized_entries)
+ {
+ Instrumentation *child = dlist_container(Instrumentation, unfinalized_entry, iter.cur);
+
+ InstrAccumStack(&qinstr->instr, child);
+ }
+
+ /* Ensure the stack is reset as expected, and we accumulate to the parent */
+ InstrStopFinalize(&qinstr->instr);
+
+ /*
+ * Destroy the dedicated instrumentation context, which frees the
+ * QueryInstrumentation and all child allocations.
+ */
+ MemoryContextDelete(instr_cxt);
+}
+
+QueryInstrumentation *
+InstrQueryAlloc(int instrument_options)
+{
+ QueryInstrumentation *instr;
+ MemoryContext instr_cxt;
+
+ /*
+ * When the instrumentation stack is used, create a dedicated memory
+ * context for this query's instrumentation allocations. This context is a
+ * child of TopMemoryContext so it survives transaction abort —
+ * ResourceOwner release needs to access it.
+ *
+ * For simpler cases (timer/rows only), use the current memory context.
+ *
+ * All child instrumentation allocations (nodes, triggers, etc) must be
+ * allocated within this context to ensure correct clean up on abort.
+ */
+ if (InstrNeedStack(instrument_options))
+ instr_cxt = AllocSetContextCreate(TopMemoryContext,
+ "Instrumentation",
+ ALLOCSET_SMALL_SIZES);
+ else
+ instr_cxt = CurrentMemoryContext;
+
+ instr = MemoryContextAllocZero(instr_cxt, sizeof(QueryInstrumentation));
+ instr->instrument_options = instrument_options;
+ instr->instr_cxt = instr_cxt;
+
+ InstrInitOptions(&instr->instr, instrument_options);
+ dlist_init(&instr->unfinalized_entries);
+
+ return instr;
+}
+
+void
+InstrQueryStart(QueryInstrumentation *qinstr)
+{
+ InstrStart(&qinstr->instr);
+
+ if (qinstr->instr.need_stack)
+ {
+ Assert(CurrentResourceOwner != NULL);
+ qinstr->owner = CurrentResourceOwner;
+
+ ResourceOwnerEnlarge(qinstr->owner);
+ ResourceOwnerRememberInstrumentation(qinstr->owner, qinstr);
+ }
+}
+
+void
+InstrQueryStop(QueryInstrumentation *qinstr)
+{
+ InstrStop(&qinstr->instr);
+
+ if (qinstr->instr.need_stack)
+ {
+ Assert(qinstr->owner != NULL);
+ ResourceOwnerForgetInstrumentation(qinstr->owner, qinstr);
+ qinstr->owner = NULL;
+ }
+}
+
+void
+InstrQueryStopFinalize(QueryInstrumentation *qinstr)
+{
+ InstrStopFinalize(&qinstr->instr);
+
+ if (!qinstr->instr.need_stack)
+ {
+ Assert(qinstr->owner == NULL);
+ return;
+ }
+
+ Assert(qinstr->owner != NULL);
+ ResourceOwnerForgetInstrumentation(qinstr->owner, qinstr);
+ qinstr->owner = NULL;
+
+ /*
+ * Reparent the dedicated instrumentation context under the current memory
+ * context, so that its lifetime is now tied to the caller's context
+ * rather than TopMemoryContext.
+ */
+ MemoryContextSetParent(qinstr->instr_cxt, CurrentMemoryContext);
+}
+
+/*
+ * Register a child Instrumentation entry for abort processing.
+ *
+ * On abort, ResOwnerReleaseInstrumentation will walk the parent's list to
+ * recover buffer/WAL data from entries that were never finalized, in order for
+ * aggregate totals to be accurate despite the query erroring out.
+ */
+void
+InstrQueryRememberChild(QueryInstrumentation *parent, Instrumentation *child)
+{
+ if (child->need_stack)
+ dlist_push_head(&parent->unfinalized_entries, &child->unfinalized_entry);
+}
+
+/* start instrumentation during parallel executor startup */
+QueryInstrumentation *
+InstrStartParallelQuery(void)
+{
+ QueryInstrumentation *qinstr = InstrQueryAlloc(INSTRUMENT_BUFFERS | INSTRUMENT_WAL);
+
+ InstrQueryStart(qinstr);
+ return qinstr;
+}
+
+/* report usage after parallel executor shutdown */
+void
+InstrEndParallelQuery(QueryInstrumentation *qinstr, BufferUsage *bufusage, WalUsage *walusage)
+{
+ InstrQueryStopFinalize(qinstr);
+ memcpy(bufusage, &qinstr->instr.bufusage, sizeof(BufferUsage));
+ memcpy(walusage, &qinstr->instr.walusage, sizeof(WalUsage));
+}
+
+/*
+ * Accumulate work done by parallel workers in the leader's stats.
+ *
+ * Note that what gets added here effectively depends on whether per-node
+ * instrumentation is active. If it's active the parallel worker intentionally
+ * skips ExecFinalizeNodeInstrumentation on executor shutdown, because it would
+ * cause double counting. Instead, this only accumulates any extra activity
+ * outside of nodes.
+ *
+ * Otherwise this is responsible for making sure that the complete query
+ * activity is accumulated.
+ */
+void
+InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
+{
+ BufferUsageAdd(&instr_stack.current->bufusage, bufusage);
+ WalUsageAdd(&instr_stack.current->walusage, walusage);
+
+ WalUsageAdd(&pgWalUsage, walusage);
+}
+
/* Node instrumentation handling */
/* Allocate new node instrumentation structure */
NodeInstrumentation *
-InstrAllocNode(int instrument_options, bool async_mode)
+InstrAllocNode(QueryInstrumentation *qinstr, int instrument_options,
+ bool async_mode)
{
- NodeInstrumentation *instr = palloc_object(NodeInstrumentation);
+ NodeInstrumentation *instr = MemoryContextAlloc(qinstr->instr_cxt, sizeof(NodeInstrumentation));
InstrInitNode(instr, instrument_options, async_mode);
+ InstrQueryRememberChild(qinstr, &instr->instr);
+
return instr;
}
@@ -129,6 +405,7 @@ InstrStartNode(NodeInstrumentation *instr)
InstrStart(&instr->instr);
}
+
/* Exit from a plan node */
void
InstrStopNode(NodeInstrumentation *instr, double nTuples)
@@ -180,8 +457,8 @@ InstrEndLoop(NodeInstrumentation *instr)
if (!instr->running)
return;
- if (!INSTR_TIME_IS_ZERO(instr->instr.starttime))
- elog(ERROR, "InstrEndLoop called on running node");
+ /* Ensure InstrNodeStop was called */
+ Assert(INSTR_TIME_IS_ZERO(instr->instr.starttime));
/* Accumulate per-cycle statistics into totals */
INSTR_TIME_ADD(instr->startup, instr->firsttuple);
@@ -214,22 +491,30 @@ InstrAggNode(NodeInstrumentation *dst, NodeInstrumentation *add)
dst->nfiltered1 += add->nfiltered1;
dst->nfiltered2 += add->nfiltered2;
- if (dst->instr.need_bufusage)
- BufferUsageAdd(&dst->instr.bufusage, &add->instr.bufusage);
-
- if (dst->instr.need_walusage)
- WalUsageAdd(&dst->instr.walusage, &add->instr.walusage);
+ if (dst->instr.need_stack)
+ InstrAccumStack(&dst->instr, &add->instr);
}
/* Trigger instrumentation handling */
TriggerInstrumentation *
-InstrAllocTrigger(int n, int instrument_options)
+InstrAllocTrigger(QueryInstrumentation *qinstr, int instrument_options, int n)
{
- TriggerInstrumentation *tginstr = palloc0_array(TriggerInstrumentation, n);
+ TriggerInstrumentation *tginstr;
int i;
+ /*
+ * Allocate in the query's dedicated instrumentation context so all
+ * instrumentation data is grouped together and cleaned up as a unit.
+ */
+ Assert(qinstr != NULL && qinstr->instr_cxt != NULL);
+ tginstr = MemoryContextAllocZero(qinstr->instr_cxt,
+ n * sizeof(TriggerInstrumentation));
+
for (i = 0; i < n; i++)
+ {
InstrInitOptions(&tginstr[i].instr, instrument_options);
+ InstrQueryRememberChild(qinstr, &tginstr[i].instr);
+ }
return tginstr;
}
@@ -243,38 +528,30 @@ InstrStartTrigger(TriggerInstrumentation *tginstr)
void
InstrStopTrigger(TriggerInstrumentation *tginstr, int64 firings)
{
+ /*
+ * This trigger may be called again, so we don't finalize instrumentation
+ * here. Accumulation to the parent happens at ExecutorFinish through
+ * ExecFinalizeTriggerInstrumentation.
+ */
InstrStop(&tginstr->instr);
tginstr->firings += firings;
}
-/* note current values during parallel executor startup */
void
-InstrStartParallelQuery(void)
+InstrAccumStack(Instrumentation *dst, Instrumentation *add)
{
- save_pgBufferUsage = pgBufferUsage;
- save_pgWalUsage = pgWalUsage;
-}
+ Assert(dst != NULL);
+ Assert(add != NULL);
-/* report usage after parallel executor shutdown */
-void
-InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
-{
- memset(bufusage, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(bufusage, &pgBufferUsage, &save_pgBufferUsage);
- memset(walusage, 0, sizeof(WalUsage));
- WalUsageAccumDiff(walusage, &pgWalUsage, &save_pgWalUsage);
-}
+ if (!add->need_stack)
+ return;
-/* accumulate work done by workers in leader's stats */
-void
-InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
-{
- BufferUsageAdd(&pgBufferUsage, bufusage);
- WalUsageAdd(&pgWalUsage, walusage);
+ BufferUsageAdd(&dst->bufusage, &add->bufusage);
+ WalUsageAdd(&dst->walusage, &add->walusage);
}
/* dst += add */
-static void
+void
BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
{
dst->shared_blks_hit += add->shared_blks_hit;
@@ -295,39 +572,9 @@ BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
INSTR_TIME_ADD(dst->temp_blk_write_time, add->temp_blk_write_time);
}
-/* dst += add - sub */
+/* dst += add */
void
-BufferUsageAccumDiff(BufferUsage *dst,
- const BufferUsage *add,
- const BufferUsage *sub)
-{
- dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
- dst->shared_blks_read += add->shared_blks_read - sub->shared_blks_read;
- dst->shared_blks_dirtied += add->shared_blks_dirtied - sub->shared_blks_dirtied;
- dst->shared_blks_written += add->shared_blks_written - sub->shared_blks_written;
- dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
- dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
- dst->local_blks_dirtied += add->local_blks_dirtied - sub->local_blks_dirtied;
- dst->local_blks_written += add->local_blks_written - sub->local_blks_written;
- dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
- dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written;
- INSTR_TIME_ACCUM_DIFF(dst->shared_blk_read_time,
- add->shared_blk_read_time, sub->shared_blk_read_time);
- INSTR_TIME_ACCUM_DIFF(dst->shared_blk_write_time,
- add->shared_blk_write_time, sub->shared_blk_write_time);
- INSTR_TIME_ACCUM_DIFF(dst->local_blk_read_time,
- add->local_blk_read_time, sub->local_blk_read_time);
- INSTR_TIME_ACCUM_DIFF(dst->local_blk_write_time,
- add->local_blk_write_time, sub->local_blk_write_time);
- INSTR_TIME_ACCUM_DIFF(dst->temp_blk_read_time,
- add->temp_blk_read_time, sub->temp_blk_read_time);
- INSTR_TIME_ACCUM_DIFF(dst->temp_blk_write_time,
- add->temp_blk_write_time, sub->temp_blk_write_time);
-}
-
-/* helper functions for WAL usage accumulation */
-static void
-WalUsageAdd(WalUsage *dst, WalUsage *add)
+WalUsageAdd(WalUsage *dst, const WalUsage *add)
{
dst->wal_bytes += add->wal_bytes;
dst->wal_records += add->wal_records;
diff --git a/src/backend/replication/logical/worker.c b/src/backend/replication/logical/worker.c
index b38170f0fbe..a829ddf5acb 100644
--- a/src/backend/replication/logical/worker.c
+++ b/src/backend/replication/logical/worker.c
@@ -904,7 +904,7 @@ create_edata_for_relation(LogicalRepRelMapEntry *rel)
* Use Relation opened by logicalrep_rel_open() instead of opening it
* again.
*/
- InitResultRelInfo(resultRelInfo, rel->localrel, 1, NULL, 0);
+ InitResultRelInfo(resultRelInfo, rel->localrel, 1, NULL, 0, NULL);
/*
* We put the ResultRelInfo in the es_opened_result_relations list, even
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index 3e1c39160db..cf4f4246ca2 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -1266,9 +1266,9 @@ PinBufferForBlock(Relation rel,
if (rel)
{
/*
- * While pgBufferUsage's "read" counter isn't bumped unless we reach
- * WaitReadBuffers() (so, not for hits, and not for buffers that are
- * zeroed instead), the per-relation stats always count them.
+ * While the current buffer usage "read" counter isn't bumped unless
+ * we reach WaitReadBuffers() (so, not for hits, and not for buffers
+ * that are zeroed instead), the per-relation stats always count them.
*/
pgstat_count_buffer_read(rel);
}
diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c
index e3829d7fe7c..e7fc7f071d8 100644
--- a/src/backend/utils/activity/pgstat_io.c
+++ b/src/backend/utils/activity/pgstat_io.c
@@ -114,9 +114,9 @@ pgstat_prepare_io_time(bool track_io_guc)
* pg_stat_database only counts block read and write times, these are done for
* IOOP_READ, IOOP_WRITE and IOOP_EXTEND.
*
- * pgBufferUsage is used for EXPLAIN. pgBufferUsage has write and read stats
- * for shared, local and temporary blocks. pg_stat_io does not track the
- * activity of temporary blocks, so these are ignored here.
+ * Executor instrumentation is used for EXPLAIN. Buffer usage tracked there has
+ * write and read stats for shared, local and temporary blocks. pg_stat_io
+ * does not track the activity of temporary blocks, so these are ignored here.
*/
void
pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op,
diff --git a/src/include/executor/executor.h b/src/include/executor/executor.h
index 491c4886506..78961ae058b 100644
--- a/src/include/executor/executor.h
+++ b/src/include/executor/executor.h
@@ -233,6 +233,7 @@ ExecGetJunkAttribute(TupleTableSlot *slot, AttrNumber attno, bool *isNull)
/*
* prototypes from functions in execMain.c
*/
+typedef struct QueryInstrumentation QueryInstrumentation;
extern void ExecutorStart(QueryDesc *queryDesc, int eflags);
extern void standard_ExecutorStart(QueryDesc *queryDesc, int eflags);
extern void ExecutorRun(QueryDesc *queryDesc,
@@ -254,7 +255,8 @@ extern void InitResultRelInfo(ResultRelInfo *resultRelInfo,
Relation resultRelationDesc,
Index resultRelationIndex,
ResultRelInfo *partition_root_rri,
- int instrument_options);
+ int instrument_options,
+ QueryInstrumentation *qinstr);
extern ResultRelInfo *ExecGetTriggerResultRel(EState *estate, Oid relid,
ResultRelInfo *rootRelInfo);
extern List *ExecGetAncestorResultRels(EState *estate, ResultRelInfo *resultRelInfo);
@@ -301,6 +303,8 @@ extern void ExecSetExecProcNode(PlanState *node, ExecProcNodeMtd function);
extern Node *MultiExecProcNode(PlanState *node);
extern void ExecEndNode(PlanState *node);
extern void ExecShutdownNode(PlanState *node);
+extern void ExecFinalizeNodeInstrumentation(PlanState *node);
+extern void ExecFinalizeWorkerInstrumentation(PlanState *node);
extern void ExecSetTupleBound(int64 tuples_needed, PlanState *child_node);
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 5261356dba6..f5cc6fb662b 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -13,6 +13,7 @@
#ifndef INSTRUMENT_H
#define INSTRUMENT_H
+#include "lib/ilist.h"
#include "portability/instr_time.h"
@@ -68,29 +69,92 @@ typedef enum InstrumentOption
} InstrumentOption;
/*
- * General purpose instrumentation that can capture time and WAL/buffer usage
+ * Instrumentation base class for capturing time and WAL/buffer usage
*
- * Initialized through InstrAlloc, followed by one or more calls to a pair of
- * InstrStart/InstrStop (activity is measured in between).
+ * If used directly:
+ * - Allocate on the stack and zero initialize the struct
+ * - Call InstrInitOptions to set instrumentation options
+ * - Call InstrStart before the activity you want to measure
+ * - Call InstrStop / InstrStopFinalize after the activity to capture totals
+ *
+ * InstrStart/InstrStop may be called multiple times. The last stop call must
+ * be to InstrStopFinalize to ensure parent stack entries get the accumulated
+ * totals. If there is risk of transaction aborts you must call
+ * InstrStopFinalize in a PG_TRY/PG_FINALLY block to avoid corrupting the
+ * instrumentation stack.
+ *
+ * In a query context use QueryInstrumentation instead, which handles aborts
+ * using the resource owner logic.
*/
typedef struct Instrumentation
{
/* Parameters set at creation: */
bool need_timer; /* true if we need timer data */
- bool need_bufusage; /* true if we need buffer usage data */
- bool need_walusage; /* true if we need WAL usage data */
+ bool need_stack; /* true if we need WAL/buffer usage data */
/* Internal state keeping: */
+ bool on_stack; /* true if currently on instr_stack */
instr_time starttime; /* start time of last InstrStart */
- BufferUsage bufusage_start; /* buffer usage at start */
- WalUsage walusage_start; /* WAL usage at start */
/* Accumulated statistics: */
instr_time total; /* total runtime */
BufferUsage bufusage; /* total buffer usage */
WalUsage walusage; /* total WAL usage */
+ /* Abort handling: link in parent QueryInstrumentation's unfinalized list */
+ dlist_node unfinalized_entry;
} Instrumentation;
+/*
+ * Query-related instrumentation tracking.
+ *
+ * Usage:
+ * - Allocate on the heap using InstrQueryAlloc (required for abort handling)
+ * - Call InstrQueryStart before the activity you want to measure
+ * - Call InstrQueryStop / InstrQueryStopFinalize afterwards to capture totals
+ *
+ * InstrQueryStart/InstrQueryStop may be called multiple times. The last stop
+ * call must be to InstrQueryStopFinalize to ensure parent stack entries get
+ * the accumulated totals.
+ *
+ * Uses resource owner mechanism for handling aborts, as such, the caller
+ * *must* not exit out of the top level transaction after having called
+ * InstrQueryStart, without first calling InstrQueryStop or
+ * InstrQueryStopFinalize. In the case of a transaction abort, logic equivalent
+ * to InstrQueryStopFinalize will be called automatically.
+ */
+struct ResourceOwnerData;
+typedef struct QueryInstrumentation
+{
+ Instrumentation instr;
+
+ /* Original instrument_options flags used to create this instrumentation */
+ int instrument_options;
+
+ /* Resource owner used for cleanup for aborts between InstrStart/InstrStop */
+ struct ResourceOwnerData *owner;
+
+ /*
+ * Dedicated memory context for all instrumentation allocations belonging
+ * to this query (node instrumentation, trigger instrumentation, etc.).
+ * Initially a child of TopMemoryContext so it survives transaction abort
+ * for ResourceOwner cleanup, which is then reassigned to the current
+ * memory context on InstrQueryStopFinalize.
+ */
+ MemoryContext instr_cxt;
+
+ /*
+ * Child entries that need to be cleaned up on abort, since they are not
+ * registered as a resource owner themselves. Contains both node and
+ * trigger instrumentation entries linked via instr.unfinalized_entry.
+ */
+ dlist_head unfinalized_entries;
+} QueryInstrumentation;
+
/*
* Specialized instrumentation for per-node execution statistics
+ *
+ * Relies on an outer QueryInstrumentation having been set up to handle the
+ * stack used for WAL/buffer usage statistics, and relies on it for managing
+ * aborts. Solely intended for the executor and anyone reporting about its
+ * activities (e.g. EXPLAIN ANALYZE).
*/
typedef struct NodeInstrumentation
{
@@ -111,6 +175,10 @@ typedef struct NodeInstrumentation
double nfiltered2; /* # of tuples removed by "other" quals */
} NodeInstrumentation;
+/*
+ * Care must be taken with any pointers contained within this struct, as this
+ * gets copied across processes during parallel query execution.
+ */
typedef struct WorkerNodeInstrumentation
{
int num_workers; /* # of structures that follow */
@@ -124,15 +192,105 @@ typedef struct TriggerInstrumentation
* was fired */
} TriggerInstrumentation;
-extern PGDLLIMPORT BufferUsage pgBufferUsage;
+/*
+ * Dynamic array-based stack for tracking current WAL/buffer usage context.
+ *
+ * When the stack is empty, 'current' points to instr_top which accumulates
+ * session-level totals.
+ */
+typedef struct InstrStackState
+{
+ int stack_space; /* allocated capacity of entries array */
+ int stack_size; /* current number of entries */
+
+ Instrumentation **entries; /* dynamic array of pointers */
+ Instrumentation *current; /* top of stack, or &instr_top when empty */
+} InstrStackState;
+
extern PGDLLIMPORT WalUsage pgWalUsage;
-extern Instrumentation *InstrAlloc(int instrument_options);
+/*
+ * The top instrumentation represents a running total of the current backend
+ * WAL/buffer usage information. This will not be updated immediately, but
+ * rather when the current stack entry gets accumulated which typically happens
+ * at query end.
+ *
+ * Care must be taken when utilizing this in the parallel worker context:
+ * Parallel workers will report back their instrumentation to the caller,
+ * and this gets added to the caller's stack. If this were to be used in the
+ * shared memory stats infrastructure it would need to be skipped on parallel
+ * workers to avoid double counting.
+ */
+extern PGDLLIMPORT Instrumentation instr_top;
+
+/*
+ * The instrumentation stack state. The 'current' field points to the
+ * currently active stack entry that is getting updated as activity happens,
+ * and will be accumulated to parent stacks when it gets finalized by
+ * InstrStop (for non-executor use cases), ExecFinalizeNodeInstrumentation
+ * (executor finish) or ResOwnerReleaseInstrumentation on abort.
+ */
+extern PGDLLIMPORT InstrStackState instr_stack;
+
+extern void InstrStackGrow(void);
+
+/*
+ * Pushes the stack so that all WAL/buffer usage updates go to the passed in
+ * instrumentation entry.
+ *
+ * See note on InstrPopStack regarding safe use of these functions.
+ */
+static inline void
+InstrPushStack(Instrumentation *instr)
+{
+ if (unlikely(instr_stack.stack_size == instr_stack.stack_space))
+ InstrStackGrow();
+
+ instr_stack.entries[instr_stack.stack_size++] = instr;
+ instr_stack.current = instr;
+ instr->on_stack = true;
+}
+
+/*
+ * Pops the stack entry back to the previous one that was effective at
+ * InstrPushStack.
+ *
+ * Callers must ensure that no intermediate stack entries are skipped, to
+ * handle aborts correctly. If you're thinking of calling this in a PG_FINALLY
+ * block, consider instead using InstrStart + InstrStopFinalize which can skip
+ * intermediate stack entries.
+ */
+static inline void
+InstrPopStack(Instrumentation *instr)
+{
+ Assert(instr_stack.stack_size > 0);
+ Assert(instr_stack.entries[instr_stack.stack_size - 1] == instr);
+ instr_stack.stack_size--;
+ instr_stack.current = instr_stack.stack_size > 0
+ ? instr_stack.entries[instr_stack.stack_size - 1]
+ : &instr_top;
+ instr->on_stack = false;
+}
+
extern void InstrInitOptions(Instrumentation *instr, int instrument_options);
extern void InstrStart(Instrumentation *instr);
extern void InstrStop(Instrumentation *instr);
+extern void InstrStopFinalize(Instrumentation *instr);
+extern void InstrFinalizeChild(Instrumentation *instr, Instrumentation *parent);
+extern void InstrAccumStack(Instrumentation *dst, Instrumentation *add);
-extern NodeInstrumentation *InstrAllocNode(int instrument_options,
+extern QueryInstrumentation *InstrQueryAlloc(int instrument_options);
+extern void InstrQueryStart(QueryInstrumentation *instr);
+extern void InstrQueryStop(QueryInstrumentation *instr);
+extern void InstrQueryStopFinalize(QueryInstrumentation *instr);
+extern void InstrQueryRememberChild(QueryInstrumentation *parent, Instrumentation *instr);
+
+pg_nodiscard extern QueryInstrumentation *InstrStartParallelQuery(void);
+extern void InstrEndParallelQuery(QueryInstrumentation *qinstr, BufferUsage *bufusage, WalUsage *walusage);
+extern void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
+
+extern NodeInstrumentation *InstrAllocNode(QueryInstrumentation *qinstr,
+ int instrument_options,
bool async_mode);
extern void InstrInitNode(NodeInstrumentation *instr, int instrument_options,
bool async_mode);
@@ -142,35 +300,36 @@ extern void InstrUpdateTupleCount(NodeInstrumentation *instr, double nTuples);
extern void InstrEndLoop(NodeInstrumentation *instr);
extern void InstrAggNode(NodeInstrumentation *dst, NodeInstrumentation *add);
-extern TriggerInstrumentation *InstrAllocTrigger(int n, int instrument_options);
+extern TriggerInstrumentation *InstrAllocTrigger(QueryInstrumentation *qinstr,
+ int instrument_options, int n);
extern void InstrStartTrigger(TriggerInstrumentation *tginstr);
extern void InstrStopTrigger(TriggerInstrumentation *tginstr, int64 firings);
-extern void InstrStartParallelQuery(void);
-extern void InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
-extern void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
-extern void BufferUsageAccumDiff(BufferUsage *dst,
- const BufferUsage *add, const BufferUsage *sub);
+extern void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
+extern void WalUsageAdd(WalUsage *dst, const WalUsage *add);
extern void WalUsageAccumDiff(WalUsage *dst, const WalUsage *add,
const WalUsage *sub);
#define INSTR_BUFUSAGE_INCR(fld) do { \
- pgBufferUsage.fld++; \
+ instr_stack.current->bufusage.fld++; \
} while(0)
#define INSTR_BUFUSAGE_ADD(fld,val) do { \
- pgBufferUsage.fld += (val); \
+ instr_stack.current->bufusage.fld += (val); \
} while(0)
#define INSTR_BUFUSAGE_TIME_ADD(fld,val) do { \
- INSTR_TIME_ADD(pgBufferUsage.fld, val); \
+ INSTR_TIME_ADD(instr_stack.current->bufusage.fld, val); \
} while (0)
#define INSTR_BUFUSAGE_TIME_ACCUM_DIFF(fld,endval,startval) do { \
- INSTR_TIME_ACCUM_DIFF(pgBufferUsage.fld, endval, startval); \
+ INSTR_TIME_ACCUM_DIFF(instr_stack.current->bufusage.fld, endval, startval); \
} while (0)
+
#define INSTR_WALUSAGE_INCR(fld) do { \
pgWalUsage.fld++; \
+ instr_stack.current->walusage.fld++; \
} while(0)
#define INSTR_WALUSAGE_ADD(fld,val) do { \
pgWalUsage.fld += (val); \
+ instr_stack.current->walusage.fld += (val); \
} while(0)
#endif /* INSTRUMENT_H */
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index 3ecae7552fc..491c4e272d8 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -54,6 +54,7 @@ typedef struct Instrumentation Instrumentation;
typedef struct pairingheap pairingheap;
typedef struct PlanState PlanState;
typedef struct QueryEnvironment QueryEnvironment;
+typedef struct QueryInstrumentation QueryInstrumentation;
typedef struct RelationData *Relation;
typedef Relation *RelationPtr;
typedef struct ScanKeyData ScanKeyData;
@@ -754,6 +755,7 @@ typedef struct EState
int es_top_eflags; /* eflags passed to ExecutorStart */
int es_instrument; /* OR of InstrumentOption flags */
+ QueryInstrumentation *es_query_instr; /* query-level instrumentation */
bool es_finished; /* true when ExecutorFinish is done */
List *es_exprcontexts; /* List of ExprContexts within EState */
diff --git a/src/include/utils/resowner.h b/src/include/utils/resowner.h
index eb6033b4fdb..5463bc921f0 100644
--- a/src/include/utils/resowner.h
+++ b/src/include/utils/resowner.h
@@ -75,6 +75,7 @@ typedef uint32 ResourceReleasePriority;
#define RELEASE_PRIO_SNAPSHOT_REFS 500
#define RELEASE_PRIO_FILES 600
#define RELEASE_PRIO_WAITEVENTSETS 700
+#define RELEASE_PRIO_INSTRUMENTATION 800
/* 0 is considered invalid */
#define RELEASE_PRIO_FIRST 1
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 35acda59851..b639c360cea 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1357,6 +1357,7 @@ InjectionPointSharedState
InjectionPointsCtl
InlineCodeBlock
InsertStmt
+InstrStackState
Instrumentation
Int128AggState
Int8TransTypeData
@@ -2479,6 +2480,7 @@ QueryCompletion
QueryDesc
QueryEnvironment
QueryInfo
+QueryInstrumentation
QueryItem
QueryItemType
QueryMode
--
2.47.1
[application/octet-stream] v15-0009-Add-test_session_buffer_usage-test-module.patch (30.0K, 11-v15-0009-Add-test_session_buffer_usage-test-module.patch)
download | inline diff:
From c95f0246b23f14205bb5eb68014b8d080c01cc03 Mon Sep 17 00:00:00 2001
From: Lukas Fittl <[email protected]>
Date: Sat, 7 Mar 2026 11:46:41 -0800
Subject: [PATCH v15 9/9] Add test_session_buffer_usage test 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.
---
src/test/modules/Makefile | 1 +
src/test/modules/meson.build | 1 +
.../test_session_buffer_usage/Makefile | 23 ++
.../expected/test_session_buffer_usage.out | 342 ++++++++++++++++++
.../test_session_buffer_usage/meson.build | 33 ++
.../sql/test_session_buffer_usage.sql | 245 +++++++++++++
.../test_session_buffer_usage--1.0.sql | 31 ++
.../test_session_buffer_usage.c | 95 +++++
.../test_session_buffer_usage.control | 5 +
9 files changed, 776 insertions(+)
create mode 100644 src/test/modules/test_session_buffer_usage/Makefile
create mode 100644 src/test/modules/test_session_buffer_usage/expected/test_session_buffer_usage.out
create mode 100644 src/test/modules/test_session_buffer_usage/meson.build
create mode 100644 src/test/modules/test_session_buffer_usage/sql/test_session_buffer_usage.sql
create mode 100644 src/test/modules/test_session_buffer_usage/test_session_buffer_usage--1.0.sql
create mode 100644 src/test/modules/test_session_buffer_usage/test_session_buffer_usage.c
create mode 100644 src/test/modules/test_session_buffer_usage/test_session_buffer_usage.control
diff --git a/src/test/modules/Makefile b/src/test/modules/Makefile
index f1b04c99969..e74e327701b 100644
--- a/src/test/modules/Makefile
+++ b/src/test/modules/Makefile
@@ -48,6 +48,7 @@ SUBDIRS = \
test_resowner \
test_rls_hooks \
test_saslprep \
+ test_session_buffer_usage \
test_shmem \
test_shm_mq \
test_slru \
diff --git a/src/test/modules/meson.build b/src/test/modules/meson.build
index fc99552d9ab..5c46ec13918 100644
--- a/src/test/modules/meson.build
+++ b/src/test/modules/meson.build
@@ -49,6 +49,7 @@ subdir('test_regex')
subdir('test_resowner')
subdir('test_rls_hooks')
subdir('test_saslprep')
+subdir('test_session_buffer_usage')
subdir('test_shmem')
subdir('test_shm_mq')
subdir('test_slru')
diff --git a/src/test/modules/test_session_buffer_usage/Makefile b/src/test/modules/test_session_buffer_usage/Makefile
new file mode 100644
index 00000000000..1252b222cb9
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/Makefile
@@ -0,0 +1,23 @@
+# src/test/modules/test_session_buffer_usage/Makefile
+
+MODULE_big = test_session_buffer_usage
+OBJS = \
+ $(WIN32RES) \
+ test_session_buffer_usage.o
+
+EXTENSION = test_session_buffer_usage
+DATA = test_session_buffer_usage--1.0.sql
+PGFILEDESC = "test_session_buffer_usage - show buffer usage statistics for the current session"
+
+REGRESS = test_session_buffer_usage
+
+ifdef USE_PGXS
+PG_CONFIG = pg_config
+PGXS := $(shell $(PG_CONFIG) --pgxs)
+include $(PGXS)
+else
+subdir = src/test/modules/test_session_buffer_usage
+top_builddir = ../../../..
+include $(top_builddir)/src/Makefile.global
+include $(top_srcdir)/contrib/contrib-global.mk
+endif
diff --git a/src/test/modules/test_session_buffer_usage/expected/test_session_buffer_usage.out b/src/test/modules/test_session_buffer_usage/expected/test_session_buffer_usage.out
new file mode 100644
index 00000000000..5f7d349871a
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/expected/test_session_buffer_usage.out
@@ -0,0 +1,342 @@
+LOAD 'test_session_buffer_usage';
+CREATE EXTENSION test_session_buffer_usage;
+-- Verify all columns are non-negative
+SELECT count(*) = 1 AS ok FROM test_session_buffer_usage()
+WHERE shared_blks_hit >= 0 AND shared_blks_read >= 0
+ AND shared_blks_dirtied >= 0 AND shared_blks_written >= 0
+ AND local_blks_hit >= 0 AND local_blks_read >= 0
+ AND local_blks_dirtied >= 0 AND local_blks_written >= 0
+ AND temp_blks_read >= 0 AND temp_blks_written >= 0
+ AND shared_blk_read_time >= 0 AND shared_blk_write_time >= 0
+ AND local_blk_read_time >= 0 AND local_blk_write_time >= 0
+ AND temp_blk_read_time >= 0 AND temp_blk_write_time >= 0;
+ ok
+----
+ t
+(1 row)
+
+-- Verify counters increase after buffer activity
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+CREATE TEMP TABLE test_buf_activity (id int, data text);
+INSERT INTO test_buf_activity SELECT i, repeat('x', 100) FROM generate_series(1, 1000) AS i;
+SELECT count(*) FROM test_buf_activity;
+ count
+-------
+ 1000
+(1 row)
+
+SELECT local_blks_hit + local_blks_read > 0 AS blocks_increased
+FROM test_session_buffer_usage();
+ blocks_increased
+------------------
+ t
+(1 row)
+
+DROP TABLE test_buf_activity;
+-- Parallel query test
+CREATE TABLE par_dc_tab (a int, b char(200));
+INSERT INTO par_dc_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+SELECT count(*) FROM par_dc_tab;
+ count
+-------
+ 5000
+(1 row)
+
+-- Measure serial scan delta (leader does all the work)
+SET max_parallel_workers_per_gather = 0;
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT count(*) FROM par_dc_tab;
+ count
+-------
+ 5000
+(1 row)
+
+CREATE TEMP TABLE dc_serial_result AS
+SELECT shared_blks_hit AS serial_delta FROM test_session_buffer_usage();
+-- Measure parallel scan delta with leader NOT participating in scanning.
+-- Workers do all table scanning; leader only runs the Gather node.
+SET parallel_setup_cost = 0;
+SET parallel_tuple_cost = 0;
+SET min_parallel_table_scan_size = 0;
+SET max_parallel_workers_per_gather = 2;
+SET parallel_leader_participation = off;
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT count(*) FROM par_dc_tab;
+ count
+-------
+ 5000
+(1 row)
+
+-- Confirm we got a similar hit counter through parallel worker accumulation
+SELECT shared_blks_hit > s.serial_delta / 2 AND shared_blks_hit < s.serial_delta * 2
+ AS leader_buffers_match
+FROM test_session_buffer_usage(), dc_serial_result s;
+ leader_buffers_match
+----------------------
+ t
+(1 row)
+
+RESET parallel_setup_cost;
+RESET parallel_tuple_cost;
+RESET min_parallel_table_scan_size;
+RESET max_parallel_workers_per_gather;
+RESET parallel_leader_participation;
+DROP TABLE par_dc_tab, dc_serial_result;
+--
+-- Abort/exception tests: verify buffer usage survives various error paths.
+--
+-- Rolled-back divide-by-zero under EXPLAIN ANALYZE
+CREATE TEMP TABLE exc_tab (a int, b char(20));
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ WITH ins AS (INSERT INTO exc_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 FROM ins;
+ERROR: division by zero
+SELECT local_blks_dirtied > 0 AS exception_buffers_visible
+FROM test_session_buffer_usage();
+ exception_buffers_visible
+---------------------------
+ t
+(1 row)
+
+DROP TABLE exc_tab;
+-- Unique constraint violation in regular query
+CREATE TEMP TABLE unique_tab (a int UNIQUE, b char(20));
+INSERT INTO unique_tab VALUES (1, 'first');
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+INSERT INTO unique_tab VALUES (1, 'duplicate');
+ERROR: duplicate key value violates unique constraint "unique_tab_a_key"
+DETAIL: Key (a)=(1) already exists.
+SELECT local_blks_hit > 0 AS unique_violation_buffers_visible
+FROM test_session_buffer_usage();
+ unique_violation_buffers_visible
+----------------------------------
+ t
+(1 row)
+
+DROP TABLE unique_tab;
+-- Caught exception in PL/pgSQL subtransaction (BEGIN...EXCEPTION)
+CREATE TEMP TABLE subxact_tab (a int, b char(20));
+CREATE FUNCTION subxact_exc_func() RETURNS text AS $$
+BEGIN
+ BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ WITH ins AS (INSERT INTO subxact_tab VALUES (1, ''aaa'') RETURNING a)
+ SELECT a / 0 FROM ins';
+ EXCEPTION WHEN division_by_zero THEN
+ RETURN 'caught';
+ END;
+ RETURN 'not reached';
+END;
+$$ LANGUAGE plpgsql;
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT subxact_exc_func();
+ subxact_exc_func
+------------------
+ caught
+(1 row)
+
+SELECT local_blks_dirtied > 0 AS subxact_buffers_visible
+FROM test_session_buffer_usage();
+ subxact_buffers_visible
+-------------------------
+ t
+(1 row)
+
+DROP FUNCTION subxact_exc_func;
+DROP TABLE subxact_tab;
+-- Cursor (FOR loop) in aborted subtransaction; verify post-exception tracking
+CREATE TEMP TABLE cursor_tab (a int, b char(200));
+INSERT INTO cursor_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
+CREATE FUNCTION cursor_exc_func() RETURNS text AS $$
+DECLARE
+ rec record;
+ cnt int := 0;
+BEGIN
+ BEGIN
+ FOR rec IN SELECT * FROM cursor_tab LOOP
+ cnt := cnt + 1;
+ IF cnt = 250 THEN
+ PERFORM 1 / 0;
+ END IF;
+ END LOOP;
+ EXCEPTION WHEN division_by_zero THEN
+ RETURN 'caught after ' || cnt || ' rows';
+ END;
+ RETURN 'not reached';
+END;
+$$ LANGUAGE plpgsql;
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT cursor_exc_func();
+ cursor_exc_func
+-----------------------
+ caught after 250 rows
+(1 row)
+
+SELECT local_blks_hit + local_blks_read > 0
+ AS cursor_subxact_buffers_visible
+FROM test_session_buffer_usage();
+ cursor_subxact_buffers_visible
+--------------------------------
+ t
+(1 row)
+
+DROP FUNCTION cursor_exc_func;
+DROP TABLE cursor_tab;
+-- Trigger abort under EXPLAIN ANALYZE: verify that buffer activity from a
+-- trigger that throws an error is still properly propagated.
+CREATE TEMP TABLE trig_err_tab (a int);
+CREATE TEMP TABLE trig_work_tab (a int, b char(200));
+INSERT INTO trig_work_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
+-- Warm local buffers so trig_work_tab reads become hits
+SELECT count(*) FROM trig_work_tab;
+ count
+-------
+ 500
+(1 row)
+
+CREATE FUNCTION trig_err_func() RETURNS trigger AS $$
+BEGIN
+ PERFORM count(*) FROM trig_work_tab;
+ RAISE EXCEPTION 'trigger error';
+ RETURN NEW;
+END;
+$$ LANGUAGE plpgsql;
+CREATE TRIGGER trig_err BEFORE INSERT ON trig_err_tab
+ FOR EACH ROW EXECUTE FUNCTION trig_err_func();
+-- Measure how many local buffer hits a scan of trig_work_tab produces
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT count(*) FROM trig_work_tab;
+ count
+-------
+ 500
+(1 row)
+
+CREATE TEMP TABLE trig_serial_result AS
+SELECT local_blks_hit AS serial_hits FROM test_session_buffer_usage();
+-- Now trigger the same scan via a trigger that errors
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ INSERT INTO trig_err_tab VALUES (1);
+ERROR: trigger error
+CONTEXT: PL/pgSQL function trig_err_func() line 4 at RAISE
+-- The trigger scanned trig_work_tab but errored before InstrStopTrigger ran.
+-- InstrStopFinalize in the PG_CATCH ensures buffer data is still propagated.
+SELECT local_blks_hit >= s.serial_hits / 2
+ AS trigger_abort_buffers_propagated
+FROM test_session_buffer_usage(), trig_serial_result s;
+ trigger_abort_buffers_propagated
+----------------------------------
+ t
+(1 row)
+
+DROP TABLE trig_err_tab, trig_work_tab, trig_serial_result;
+DROP FUNCTION trig_err_func;
+-- Parallel worker abort: worker buffer activity is currently NOT propagated on abort.
+--
+-- When a parallel worker aborts, InstrEndParallelQuery and
+-- ExecParallelReportInstrumentation never run, so the worker's buffer
+-- activity is never written to shared memory, despite the information having been
+-- captured by the res owner release instrumentation handling.
+CREATE TABLE par_abort_tab (a int, b char(200));
+INSERT INTO par_abort_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+-- Warm shared buffers so all reads become hits
+SELECT count(*) FROM par_abort_tab;
+ count
+-------
+ 5000
+(1 row)
+
+-- Measure serial scan delta as a reference (leader reads all blocks)
+SET max_parallel_workers_per_gather = 0;
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
+ERROR: invalid input syntax for type smallint: "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"
+CREATE TABLE par_abort_serial_result AS
+SELECT shared_blks_hit AS serial_delta FROM test_session_buffer_usage();
+-- Now force parallel with leader NOT participating in scanning
+SET parallel_setup_cost = 0;
+SET parallel_tuple_cost = 0;
+SET min_parallel_table_scan_size = 0;
+SET max_parallel_workers_per_gather = 2;
+SET parallel_leader_participation = off;
+SET debug_parallel_query = on; -- Ensure we get CONTEXT line consistently
+SELECT test_session_buffer_usage_reset();
+ test_session_buffer_usage_reset
+---------------------------------
+
+(1 row)
+
+SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
+ERROR: invalid input syntax for type smallint: "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"
+CONTEXT: parallel worker
+RESET debug_parallel_query;
+-- Workers scanned the table but aborted before reporting stats back.
+-- The leader's delta should be much less than a serial scan, documenting
+-- that worker buffer activity is lost on abort.
+SELECT shared_blks_hit < s.serial_delta / 2
+ AS worker_abort_buffers_not_propagated
+FROM test_session_buffer_usage(), par_abort_serial_result s;
+ worker_abort_buffers_not_propagated
+-------------------------------------
+ t
+(1 row)
+
+RESET parallel_setup_cost;
+RESET parallel_tuple_cost;
+RESET min_parallel_table_scan_size;
+RESET max_parallel_workers_per_gather;
+RESET parallel_leader_participation;
+DROP TABLE par_abort_tab, par_abort_serial_result;
+-- Cleanup
+DROP EXTENSION test_session_buffer_usage;
diff --git a/src/test/modules/test_session_buffer_usage/meson.build b/src/test/modules/test_session_buffer_usage/meson.build
new file mode 100644
index 00000000000..b96f67dc7fe
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/meson.build
@@ -0,0 +1,33 @@
+# Copyright (c) 2026, PostgreSQL Global Development Group
+
+test_session_buffer_usage_sources = files(
+ 'test_session_buffer_usage.c',
+)
+
+if host_system == 'windows'
+ test_session_buffer_usage_sources += rc_lib_gen.process(win32ver_rc, extra_args: [
+ '--NAME', 'test_session_buffer_usage',
+ '--FILEDESC', 'test_session_buffer_usage - show buffer usage statistics for the current session',])
+endif
+
+test_session_buffer_usage = shared_module('test_session_buffer_usage',
+ test_session_buffer_usage_sources,
+ kwargs: pg_test_mod_args,
+)
+test_install_libs += test_session_buffer_usage
+
+test_install_data += files(
+ 'test_session_buffer_usage.control',
+ 'test_session_buffer_usage--1.0.sql',
+)
+
+tests += {
+ 'name': 'test_session_buffer_usage',
+ 'sd': meson.current_source_dir(),
+ 'bd': meson.current_build_dir(),
+ 'regress': {
+ 'sql': [
+ 'test_session_buffer_usage',
+ ],
+ },
+}
diff --git a/src/test/modules/test_session_buffer_usage/sql/test_session_buffer_usage.sql b/src/test/modules/test_session_buffer_usage/sql/test_session_buffer_usage.sql
new file mode 100644
index 00000000000..daf2159c4a6
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/sql/test_session_buffer_usage.sql
@@ -0,0 +1,245 @@
+LOAD 'test_session_buffer_usage';
+CREATE EXTENSION test_session_buffer_usage;
+
+-- Verify all columns are non-negative
+SELECT count(*) = 1 AS ok FROM test_session_buffer_usage()
+WHERE shared_blks_hit >= 0 AND shared_blks_read >= 0
+ AND shared_blks_dirtied >= 0 AND shared_blks_written >= 0
+ AND local_blks_hit >= 0 AND local_blks_read >= 0
+ AND local_blks_dirtied >= 0 AND local_blks_written >= 0
+ AND temp_blks_read >= 0 AND temp_blks_written >= 0
+ AND shared_blk_read_time >= 0 AND shared_blk_write_time >= 0
+ AND local_blk_read_time >= 0 AND local_blk_write_time >= 0
+ AND temp_blk_read_time >= 0 AND temp_blk_write_time >= 0;
+
+-- Verify counters increase after buffer activity
+SELECT test_session_buffer_usage_reset();
+
+CREATE TEMP TABLE test_buf_activity (id int, data text);
+INSERT INTO test_buf_activity SELECT i, repeat('x', 100) FROM generate_series(1, 1000) AS i;
+SELECT count(*) FROM test_buf_activity;
+
+SELECT local_blks_hit + local_blks_read > 0 AS blocks_increased
+FROM test_session_buffer_usage();
+
+DROP TABLE test_buf_activity;
+
+-- Parallel query test
+CREATE TABLE par_dc_tab (a int, b char(200));
+INSERT INTO par_dc_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+
+SELECT count(*) FROM par_dc_tab;
+
+-- Measure serial scan delta (leader does all the work)
+SET max_parallel_workers_per_gather = 0;
+
+SELECT test_session_buffer_usage_reset();
+SELECT count(*) FROM par_dc_tab;
+
+CREATE TEMP TABLE dc_serial_result AS
+SELECT shared_blks_hit AS serial_delta FROM test_session_buffer_usage();
+
+-- Measure parallel scan delta with leader NOT participating in scanning.
+-- Workers do all table scanning; leader only runs the Gather node.
+SET parallel_setup_cost = 0;
+SET parallel_tuple_cost = 0;
+SET min_parallel_table_scan_size = 0;
+SET max_parallel_workers_per_gather = 2;
+SET parallel_leader_participation = off;
+
+SELECT test_session_buffer_usage_reset();
+SELECT count(*) FROM par_dc_tab;
+
+-- Confirm we got a similar hit counter through parallel worker accumulation
+SELECT shared_blks_hit > s.serial_delta / 2 AND shared_blks_hit < s.serial_delta * 2
+ AS leader_buffers_match
+FROM test_session_buffer_usage(), dc_serial_result s;
+
+RESET parallel_setup_cost;
+RESET parallel_tuple_cost;
+RESET min_parallel_table_scan_size;
+RESET max_parallel_workers_per_gather;
+RESET parallel_leader_participation;
+
+DROP TABLE par_dc_tab, dc_serial_result;
+
+--
+-- Abort/exception tests: verify buffer usage survives various error paths.
+--
+
+-- Rolled-back divide-by-zero under EXPLAIN ANALYZE
+CREATE TEMP TABLE exc_tab (a int, b char(20));
+
+SELECT test_session_buffer_usage_reset();
+
+EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ WITH ins AS (INSERT INTO exc_tab VALUES (1, 'aaa') RETURNING a)
+ SELECT a / 0 FROM ins;
+
+SELECT local_blks_dirtied > 0 AS exception_buffers_visible
+FROM test_session_buffer_usage();
+
+DROP TABLE exc_tab;
+
+-- Unique constraint violation in regular query
+CREATE TEMP TABLE unique_tab (a int UNIQUE, b char(20));
+INSERT INTO unique_tab VALUES (1, 'first');
+
+SELECT test_session_buffer_usage_reset();
+INSERT INTO unique_tab VALUES (1, 'duplicate');
+
+SELECT local_blks_hit > 0 AS unique_violation_buffers_visible
+FROM test_session_buffer_usage();
+
+DROP TABLE unique_tab;
+
+-- Caught exception in PL/pgSQL subtransaction (BEGIN...EXCEPTION)
+CREATE TEMP TABLE subxact_tab (a int, b char(20));
+
+CREATE FUNCTION subxact_exc_func() RETURNS text AS $$
+BEGIN
+ BEGIN
+ EXECUTE 'EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ WITH ins AS (INSERT INTO subxact_tab VALUES (1, ''aaa'') RETURNING a)
+ SELECT a / 0 FROM ins';
+ EXCEPTION WHEN division_by_zero THEN
+ RETURN 'caught';
+ END;
+ RETURN 'not reached';
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT test_session_buffer_usage_reset();
+SELECT subxact_exc_func();
+
+SELECT local_blks_dirtied > 0 AS subxact_buffers_visible
+FROM test_session_buffer_usage();
+
+DROP FUNCTION subxact_exc_func;
+DROP TABLE subxact_tab;
+
+-- Cursor (FOR loop) in aborted subtransaction; verify post-exception tracking
+CREATE TEMP TABLE cursor_tab (a int, b char(200));
+INSERT INTO cursor_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
+
+CREATE FUNCTION cursor_exc_func() RETURNS text AS $$
+DECLARE
+ rec record;
+ cnt int := 0;
+BEGIN
+ BEGIN
+ FOR rec IN SELECT * FROM cursor_tab LOOP
+ cnt := cnt + 1;
+ IF cnt = 250 THEN
+ PERFORM 1 / 0;
+ END IF;
+ END LOOP;
+ EXCEPTION WHEN division_by_zero THEN
+ RETURN 'caught after ' || cnt || ' rows';
+ END;
+ RETURN 'not reached';
+END;
+$$ LANGUAGE plpgsql;
+
+SELECT test_session_buffer_usage_reset();
+SELECT cursor_exc_func();
+
+SELECT local_blks_hit + local_blks_read > 0
+ AS cursor_subxact_buffers_visible
+FROM test_session_buffer_usage();
+
+DROP FUNCTION cursor_exc_func;
+DROP TABLE cursor_tab;
+
+-- Trigger abort under EXPLAIN ANALYZE: verify that buffer activity from a
+-- trigger that throws an error is still properly propagated.
+CREATE TEMP TABLE trig_err_tab (a int);
+CREATE TEMP TABLE trig_work_tab (a int, b char(200));
+INSERT INTO trig_work_tab SELECT i, repeat('x', 200) FROM generate_series(1, 500) AS i;
+
+-- Warm local buffers so trig_work_tab reads become hits
+SELECT count(*) FROM trig_work_tab;
+
+CREATE FUNCTION trig_err_func() RETURNS trigger AS $$
+BEGIN
+ PERFORM count(*) FROM trig_work_tab;
+ RAISE EXCEPTION 'trigger error';
+ RETURN NEW;
+END;
+$$ LANGUAGE plpgsql;
+
+CREATE TRIGGER trig_err BEFORE INSERT ON trig_err_tab
+ FOR EACH ROW EXECUTE FUNCTION trig_err_func();
+
+-- Measure how many local buffer hits a scan of trig_work_tab produces
+SELECT test_session_buffer_usage_reset();
+SELECT count(*) FROM trig_work_tab;
+
+CREATE TEMP TABLE trig_serial_result AS
+SELECT local_blks_hit AS serial_hits FROM test_session_buffer_usage();
+
+-- Now trigger the same scan via a trigger that errors
+SELECT test_session_buffer_usage_reset();
+EXPLAIN (ANALYZE, BUFFERS, COSTS OFF)
+ INSERT INTO trig_err_tab VALUES (1);
+
+-- The trigger scanned trig_work_tab but errored before InstrStopTrigger ran.
+-- InstrStopFinalize in the PG_CATCH ensures buffer data is still propagated.
+SELECT local_blks_hit >= s.serial_hits / 2
+ AS trigger_abort_buffers_propagated
+FROM test_session_buffer_usage(), trig_serial_result s;
+
+DROP TABLE trig_err_tab, trig_work_tab, trig_serial_result;
+DROP FUNCTION trig_err_func;
+
+-- Parallel worker abort: worker buffer activity is currently NOT propagated on abort.
+--
+-- When a parallel worker aborts, InstrEndParallelQuery and
+-- ExecParallelReportInstrumentation never run, so the worker's buffer
+-- activity is never written to shared memory, despite the information having been
+-- captured by the res owner release instrumentation handling.
+CREATE TABLE par_abort_tab (a int, b char(200));
+INSERT INTO par_abort_tab SELECT i, repeat('x', 200) FROM generate_series(1, 5000) AS i;
+
+-- Warm shared buffers so all reads become hits
+SELECT count(*) FROM par_abort_tab;
+
+-- Measure serial scan delta as a reference (leader reads all blocks)
+SET max_parallel_workers_per_gather = 0;
+
+SELECT test_session_buffer_usage_reset();
+SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
+
+CREATE TABLE par_abort_serial_result AS
+SELECT shared_blks_hit AS serial_delta FROM test_session_buffer_usage();
+
+-- Now force parallel with leader NOT participating in scanning
+SET parallel_setup_cost = 0;
+SET parallel_tuple_cost = 0;
+SET min_parallel_table_scan_size = 0;
+SET max_parallel_workers_per_gather = 2;
+SET parallel_leader_participation = off;
+SET debug_parallel_query = on; -- Ensure we get CONTEXT line consistently
+
+SELECT test_session_buffer_usage_reset();
+SELECT b::int2 FROM par_abort_tab WHERE a > 1000;
+
+RESET debug_parallel_query;
+
+-- Workers scanned the table but aborted before reporting stats back.
+-- The leader's delta should be much less than a serial scan, documenting
+-- that worker buffer activity is lost on abort.
+SELECT shared_blks_hit < s.serial_delta / 2
+ AS worker_abort_buffers_not_propagated
+FROM test_session_buffer_usage(), par_abort_serial_result s;
+
+RESET parallel_setup_cost;
+RESET parallel_tuple_cost;
+RESET min_parallel_table_scan_size;
+RESET max_parallel_workers_per_gather;
+RESET parallel_leader_participation;
+
+DROP TABLE par_abort_tab, par_abort_serial_result;
+
+-- Cleanup
+DROP EXTENSION test_session_buffer_usage;
diff --git a/src/test/modules/test_session_buffer_usage/test_session_buffer_usage--1.0.sql b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage--1.0.sql
new file mode 100644
index 00000000000..e9833be470a
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage--1.0.sql
@@ -0,0 +1,31 @@
+/* src/test/modules/test_session_buffer_usage/test_session_buffer_usage--1.0.sql */
+
+-- complain if script is sourced in psql, rather than via CREATE EXTENSION
+\echo Use "CREATE EXTENSION test_session_buffer_usage" to load this file. \quit
+
+CREATE FUNCTION test_session_buffer_usage(
+ OUT shared_blks_hit bigint,
+ OUT shared_blks_read bigint,
+ OUT shared_blks_dirtied bigint,
+ OUT shared_blks_written bigint,
+ OUT local_blks_hit bigint,
+ OUT local_blks_read bigint,
+ OUT local_blks_dirtied bigint,
+ OUT local_blks_written bigint,
+ OUT temp_blks_read bigint,
+ OUT temp_blks_written bigint,
+ OUT shared_blk_read_time double precision,
+ OUT shared_blk_write_time double precision,
+ OUT local_blk_read_time double precision,
+ OUT local_blk_write_time double precision,
+ OUT temp_blk_read_time double precision,
+ OUT temp_blk_write_time double precision
+)
+RETURNS record
+AS 'MODULE_PATHNAME', 'test_session_buffer_usage'
+LANGUAGE C PARALLEL RESTRICTED;
+
+CREATE FUNCTION test_session_buffer_usage_reset()
+RETURNS void
+AS 'MODULE_PATHNAME', 'test_session_buffer_usage_reset'
+LANGUAGE C PARALLEL RESTRICTED;
diff --git a/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.c b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.c
new file mode 100644
index 00000000000..50eb1a2ffe6
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.c
@@ -0,0 +1,95 @@
+/*-------------------------------------------------------------------------
+ *
+ * test_session_buffer_usage.c
+ * show buffer usage statistics for the current session
+ *
+ * Copyright (c) 2026, PostgreSQL Global Development Group
+ *
+ * src/test/modules/test_session_buffer_usage/test_session_buffer_usage.c
+ *-------------------------------------------------------------------------
+ */
+#include "postgres.h"
+
+#include "access/htup_details.h"
+#include "executor/instrument.h"
+#include "funcapi.h"
+#include "miscadmin.h"
+#include "utils/memutils.h"
+
+PG_MODULE_MAGIC_EXT(
+ .name = "test_session_buffer_usage",
+ .version = PG_VERSION
+);
+
+#define NUM_BUFFER_USAGE_COLUMNS 16
+
+PG_FUNCTION_INFO_V1(test_session_buffer_usage);
+PG_FUNCTION_INFO_V1(test_session_buffer_usage_reset);
+
+#define HAVE_INSTR_STACK 1 /* Change to 0 when testing before stack
+ * change */
+
+/*
+ * SQL function: test_session_buffer_usage()
+ *
+ * Returns a single row with all BufferUsage counters accumulated since the
+ * start of the session. Excludes any usage not yet added to the top of the
+ * stack (e.g. if this gets called inside a statement that also had buffer
+ * activity).
+ */
+Datum
+test_session_buffer_usage(PG_FUNCTION_ARGS)
+{
+ TupleDesc tupdesc;
+ Datum values[NUM_BUFFER_USAGE_COLUMNS];
+ bool nulls[NUM_BUFFER_USAGE_COLUMNS];
+ BufferUsage *usage;
+
+ if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
+ elog(ERROR, "return type must be a row type");
+
+ memset(nulls, 0, sizeof(nulls));
+
+#if HAVE_INSTR_STACK
+ usage = &instr_top.bufusage;
+#else
+ usage = &pgBufferUsage;
+#endif
+
+ values[0] = Int64GetDatum(usage->shared_blks_hit);
+ values[1] = Int64GetDatum(usage->shared_blks_read);
+ values[2] = Int64GetDatum(usage->shared_blks_dirtied);
+ values[3] = Int64GetDatum(usage->shared_blks_written);
+ values[4] = Int64GetDatum(usage->local_blks_hit);
+ values[5] = Int64GetDatum(usage->local_blks_read);
+ values[6] = Int64GetDatum(usage->local_blks_dirtied);
+ values[7] = Int64GetDatum(usage->local_blks_written);
+ values[8] = Int64GetDatum(usage->temp_blks_read);
+ values[9] = Int64GetDatum(usage->temp_blks_written);
+ values[10] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time));
+ values[11] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time));
+ values[12] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time));
+ values[13] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time));
+ values[14] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time));
+ values[15] = Float8GetDatum(INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time));
+
+ PG_RETURN_DATUM(HeapTupleGetDatum(heap_form_tuple(tupdesc, values, nulls)));
+}
+
+/*
+ * SQL function: test_session_buffer_usage_reset()
+ *
+ * Resets all BufferUsage counters on the top instrumentation stack to zero.
+ * Useful in tests to avoid the baseline/delta pattern.
+ */
+Datum
+test_session_buffer_usage_reset(PG_FUNCTION_ARGS)
+{
+#if HAVE_INSTR_STACK
+ memset(&instr_top.bufusage, 0, sizeof(BufferUsage));
+#else
+ memset(&pgBufferUsage, 0, sizeof(BufferUsage));
+#endif
+
+ PG_RETURN_VOID();
+}
diff --git a/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.control b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.control
new file mode 100644
index 00000000000..41cfb15a765
--- /dev/null
+++ b/src/test/modules/test_session_buffer_usage/test_session_buffer_usage.control
@@ -0,0 +1,5 @@
+# test_session_buffer_usage extension
+comment = 'show buffer usage statistics for the current session'
+default_version = '1.0'
+module_pathname = '$libdir/test_session_buffer_usage'
+relocatable = true
--
2.47.1
view thread (42+ messages) latest in thread
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], [email protected], [email protected], [email protected], [email protected], [email protected]
Subject: Re: Stack-based tracking of per-node WAL/buffer usage
In-Reply-To: <CAP53Pkzec5L=PDvF+zrPei2kM1FZH6pD2aD=zFWXwzW8oKXJBg@mail.gmail.com>
* 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