v15-0001-instrumentation-Use-Instrumentation-instead-of-m.patch
application/octet-stream
Filename: v15-0001-instrumentation-Use-Instrumentation-instead-of-m.patch
Type: application/octet-stream
Part: 4
Patch
Same data as JSON:
GET /api/v1/attachments/:id/patch
the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes.
API reference →
Format: format-patch
Series: patch v15-0001
Subject: instrumentation: Use Instrumentation instead of manual buffer tracking
| File | + | − |
|---|---|---|
| contrib/pg_stat_statements/pg_stat_statements.c | 16 | 46 |
| src/backend/access/heap/vacuumlazy.c | 7 | 8 |
| src/backend/commands/analyze.c | 15 | 16 |
| src/backend/commands/explain.c | 21 | 23 |
| src/backend/commands/explain_dr.c | 19 | 34 |
| src/backend/commands/prepare.c | 11 | 17 |
| src/include/commands/explain_dr.h | 2 | 3 |
From ae4383e786599a06d95924276a0e414f131d344d Mon Sep 17 00:00:00 2001
From: Lukas Fittl <lukas@fittl.com>
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 <lukas@fittl.com>
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