diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index 6f82a671ee..3397ea17a0 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -1021,30 +1021,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, rows = 0; /* calc differences of buffer counters. */ - bufusage.shared_blks_hit = - pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit; - bufusage.shared_blks_read = - pgBufferUsage.shared_blks_read - bufusage_start.shared_blks_read; - bufusage.shared_blks_dirtied = - pgBufferUsage.shared_blks_dirtied - bufusage_start.shared_blks_dirtied; - bufusage.shared_blks_written = - pgBufferUsage.shared_blks_written - bufusage_start.shared_blks_written; - bufusage.local_blks_hit = - pgBufferUsage.local_blks_hit - bufusage_start.local_blks_hit; - bufusage.local_blks_read = - pgBufferUsage.local_blks_read - bufusage_start.local_blks_read; - bufusage.local_blks_dirtied = - pgBufferUsage.local_blks_dirtied - bufusage_start.local_blks_dirtied; - bufusage.local_blks_written = - pgBufferUsage.local_blks_written - bufusage_start.local_blks_written; - bufusage.temp_blks_read = - pgBufferUsage.temp_blks_read - bufusage_start.temp_blks_read; - bufusage.temp_blks_written = - pgBufferUsage.temp_blks_written - bufusage_start.temp_blks_written; - bufusage.blk_read_time = pgBufferUsage.blk_read_time; - INSTR_TIME_SUBTRACT(bufusage.blk_read_time, bufusage_start.blk_read_time); - bufusage.blk_write_time = pgBufferUsage.blk_write_time; - INSTR_TIME_SUBTRACT(bufusage.blk_write_time, bufusage_start.blk_write_time); + bufusage = ComputeBufferCounters(&bufusage_start, &pgBufferUsage); pgss_store(queryString, 0, /* signal that it's a utility stmt */ diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index d189b8d573..a699135268 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -359,7 +359,10 @@ ExplainOneQuery(Query *query, int cursorOptions, PlannedStmt *plan; instr_time planstart, planduration; + BufferUsage bufusage_start, + bufusage; + bufusage_start = pgBufferUsage; INSTR_TIME_SET_CURRENT(planstart); /* plan the query */ @@ -368,9 +371,12 @@ ExplainOneQuery(Query *query, int cursorOptions, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + /* calc differences of buffer counters. */ + bufusage = ComputeBufferCounters(&bufusage_start, &pgBufferUsage); + /* run it (if needed) and produce output */ ExplainOnePlan(plan, into, es, queryString, params, queryEnv, - &planduration); + &planduration, &bufusage); } } @@ -463,7 +469,8 @@ ExplainOneUtility(Node *utilityStmt, IntoClause *into, ExplainState *es, void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, const char *queryString, ParamListInfo params, - QueryEnvironment *queryEnv, const instr_time *planduration) + QueryEnvironment *queryEnv, const instr_time *planduration, + const BufferUsage *bufusage) { DestReceiver *dest; QueryDesc *queryDesc; @@ -547,6 +554,9 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, /* Create textual dump of plan tree */ ExplainPrintPlan(es, queryDesc); + if (es->summary && (planduration || es->buffers)) + ExplainOpenGroup("Planning", "Planning", true, es); + if (es->summary && planduration) { double plantime = INSTR_TIME_GET_DOUBLE(*planduration); @@ -554,6 +564,16 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es); } + if (es->summary && es->buffers) + { + es->indent += 1; + show_buffer_usage(es, bufusage); + es->indent -= 1; + } + + if (es->summary && (planduration || es->buffers)) + ExplainCloseGroup("Planning", "Planning", true, es); + /* Print info about runtime of triggers */ if (es->analyze) ExplainPrintTriggers(es, queryDesc); diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c index c4e4b6eaec..aa29a33aa6 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -616,7 +616,10 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, EState *estate = NULL; instr_time planstart; instr_time planduration; + BufferUsage bufusage_start, + bufusage; + bufusage_start = pgBufferUsage; INSTR_TIME_SET_CURRENT(planstart); /* Look it up in the hash table */ @@ -654,6 +657,9 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + /* calc differences of buffer counters. */ + bufusage = ComputeBufferCounters(&bufusage_start, &pgBufferUsage); + plan_list = cplan->stmt_list; /* Explain each query */ @@ -663,7 +669,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, if (pstmt->commandType != CMD_UTILITY) ExplainOnePlan(pstmt, into, es, query_string, paramLI, queryEnv, - &planduration); + &planduration, &bufusage); else ExplainOneUtility(pstmt->utilityStmt, into, es, query_string, paramLI, queryEnv); diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c index bc1d42bf64..2d8e435707 100644 --- a/src/backend/executor/instrument.c +++ b/src/backend/executor/instrument.c @@ -25,6 +25,33 @@ static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub); +/* Compute the difference between two BufferUsage */ +BufferUsage +ComputeBufferCounters(BufferUsage *start, BufferUsage *stop) +{ + BufferUsage result; + +#define CALC_BUFF_DIFF(x) result.x = stop->x - start->x; + CALC_BUFF_DIFF(shared_blks_hit); + CALC_BUFF_DIFF(shared_blks_read); + CALC_BUFF_DIFF(shared_blks_dirtied); + CALC_BUFF_DIFF(shared_blks_written); + CALC_BUFF_DIFF(local_blks_hit); + CALC_BUFF_DIFF(local_blks_read); + CALC_BUFF_DIFF(local_blks_dirtied); + CALC_BUFF_DIFF(local_blks_written); + CALC_BUFF_DIFF(temp_blks_read); + CALC_BUFF_DIFF(temp_blks_written); +#undef CALC_BUFF_DIFF + + result.blk_read_time = stop->blk_read_time; + INSTR_TIME_SUBTRACT(result.blk_read_time, start->blk_read_time); + result.blk_write_time = stop->blk_write_time; + INSTR_TIME_SUBTRACT(result.blk_write_time, start->blk_write_time); + + return result; +} + /* Allocate new instrumentation structure(s) */ Instrumentation * InstrAlloc(int n, int instrument_options) diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index 45027a7c47..0b7a88d958 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -78,7 +78,8 @@ extern void ExplainOneUtility(Node *utilityStmt, IntoClause *into, extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, const char *queryString, ParamListInfo params, QueryEnvironment *queryEnv, - const instr_time *planduration); + const instr_time *planduration, + const BufferUsage *bufusage); extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc); extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc); diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h index f48d46aede..2f112c051c 100644 --- a/src/include/executor/instrument.h +++ b/src/include/executor/instrument.h @@ -72,6 +72,7 @@ typedef struct WorkerInstrumentation extern PGDLLIMPORT BufferUsage pgBufferUsage; +extern BufferUsage ComputeBufferCounters(BufferUsage *start, BufferUsage *stop); extern Instrumentation *InstrAlloc(int n, int instrument_options); extern void InstrInit(Instrumentation *instr, int instrument_options); extern void InstrStartNode(Instrumentation *instr);