diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index ee0e638f33..81a18abbeb 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -372,7 +372,11 @@ ExplainOneQuery(Query *query, int cursorOptions, PlannedStmt *plan; instr_time planstart, planduration; + BufferUsage bufusage_start, + bufusage; + if (es->buffers) + bufusage_start = pgBufferUsage; INSTR_TIME_SET_CURRENT(planstart); /* plan the query */ @@ -381,9 +385,16 @@ ExplainOneQuery(Query *query, int cursorOptions, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + /* 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); + &planduration, (es->buffers ? &bufusage : NULL)); } } @@ -476,7 +487,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; @@ -560,6 +572,9 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, /* Create textual dump of plan tree */ ExplainPrintPlan(es, queryDesc); + if (es->summary && (planduration || bufusage)) + ExplainOpenGroup("Planning", "Planning", true, es); + if (es->summary && planduration) { double plantime = INSTR_TIME_GET_DOUBLE(*planduration); @@ -567,6 +582,19 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es); } + /* Show buffer usage */ + if (es->summary && bufusage) + { + if (es->format == EXPLAIN_FORMAT_TEXT) + es->indent++; + show_buffer_usage(es, bufusage); + if (es->format == EXPLAIN_FORMAT_TEXT) + es->indent--; + } + + if (es->summary && (planduration || bufusage)) + 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 284a5bfbec..80d6df8ac1 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -616,7 +616,11 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, EState *estate = NULL; instr_time planstart; instr_time planduration; + BufferUsage bufusage_start, + bufusage; + if (es->buffers) + bufusage_start = pgBufferUsage; INSTR_TIME_SET_CURRENT(planstart); /* Look it up in the hash table */ @@ -654,6 +658,13 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + /* 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 */ @@ -663,7 +674,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, if (pstmt->commandType != CMD_UTILITY) ExplainOnePlan(pstmt, into, es, query_string, paramLI, queryEnv, - &planduration); + &planduration, (es->buffers ? &bufusage : NULL)); else ExplainOneUtility(pstmt->utilityStmt, into, es, query_string, paramLI, queryEnv); diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index 54f6240e5e..739c1d0b42 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -89,7 +89,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/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index 8f31c308c6..191ea5de7f 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -105,7 +105,19 @@ select explain_filter('explain (analyze, buffers, format json) select * from int "Temp Read Blocks": N, + "Temp Written Blocks": N + }, + - "Planning Time": N.N, + + "Planning": { + + "Planning Time": N.N, + + "Shared Hit Blocks": N, + + "Shared Read Blocks": N, + + "Shared Dirtied Blocks": N, + + "Shared Written Blocks": N, + + "Local Hit Blocks": N, + + "Local Read Blocks": N, + + "Local Dirtied Blocks": N, + + "Local Written Blocks": N, + + "Temp Read Blocks": N, + + "Temp Written Blocks": N + + }, + "Triggers": [ + ], + "Execution Time": N.N + @@ -142,7 +154,19 @@ select explain_filter('explain (analyze, buffers, format xml) select * from int8 N + N + + - N.N + + + + N.N + + N + + N + + N+ + N+ + N + + N + + N + + N + + N + + N + + + + + N.N + @@ -176,7 +200,18 @@ select explain_filter('explain (analyze, buffers, format yaml) select * from int Local Written Blocks: N + Temp Read Blocks: N + Temp Written Blocks: N + - Planning Time: N.N + + Planning: + + Planning Time: N.N + + Shared Hit Blocks: N + + Shared Read Blocks: N + + Shared Dirtied Blocks: N + + Shared Written Blocks: N + + Local Hit Blocks: N + + Local Read Blocks: N + + Local Dirtied Blocks: N + + Local Written Blocks: N + + Temp Read Blocks: N + + Temp Written Blocks: N + Triggers: + Execution Time: N.N (1 row) @@ -366,9 +401,21 @@ select jsonb_pretty( "Shared Dirtied Blocks": 0, + "Shared Written Blocks": 0 + }, + + "Planning": { + + "Planning Time": 0.0, + + "Local Hit Blocks": 0, + + "Temp Read Blocks": 0, + + "Local Read Blocks": 0, + + "Shared Hit Blocks": 0, + + "Shared Read Blocks": 0, + + "Temp Written Blocks": 0, + + "Local Dirtied Blocks": 0, + + "Local Written Blocks": 0, + + "Shared Dirtied Blocks": 0, + + "Shared Written Blocks": 0 + + }, + "Triggers": [ + ], + - "Planning Time": 0.0, + "Execution Time": 0.0 + } + ]