On Tue, Jan 16, 2024 at 8:19 PM Ashutosh Bapat <ashutosh.bapat....@gmail.com> wrote: > > Using a boolean return and moving es->indent-- outside of > show_buffer_usage would be less elegant. >
I went ahead with this option so as not to break backward compatibility in any manner. Attached patch 0002 has the code and expected output changes. I have continued to use the variable "show_planning" and the new variable is named accordingly. Other options I could think of, like open_planning_section ended up being all long and rejected. I considered adding a test for EXPLAIN(memory, buffers) but explain.sql filters out Buffers: and Planning: lines, so it's not of much use. Returning from show_planning_buffers() is not necessary, but it looks consistent with show_buffer_usage() in the code block using them together. Here's how the output looks now In Text format #explain (memory, buffers) select * from pg_class; QUERY PLAN ------------------------------------------------------------- Seq Scan on pg_class (cost=0.00..18.15 rows=415 width=273) Planning: Buffers: shared hit=134 read=15 I/O Timings: shared read=0.213 Memory: used=22928 bytes, allocated=32768 bytes (5 rows) with planning time #explain (analyze, memory, buffers) select * from pg_class; QUERY PLAN --------------------------------------------------------------------------------------------------------- Seq Scan on pg_class (cost=0.00..18.15 rows=415 width=273) (actual time=0.020..0.378 rows=415 loops=1) Buffers: shared hit=14 Planning: Buffers: shared hit=134 read=15 I/O Timings: shared read=0.635 Memory: used=22928 bytes, allocated=32768 bytes Planning Time: 4.328 ms Execution Time: 1.262 ms (8 rows) Just memory option #explain (memory) select * from pg_class; QUERY PLAN ------------------------------------------------------------- Seq Scan on pg_class (cost=0.00..18.15 rows=415 width=273) Planning: Memory: used=22928 bytes, allocated=32768 bytes (3 rows) In JSON format #explain (memory, buffers, format json) select * from pg_class; (Notice Memory Used and Memory Allocated properties. QUERY PLAN --------------------------------------- [ + { + "Plan": { + ... snip ... }, + "Planning": { + "Shared Hit Blocks": 152, + "Shared Read Blocks": 0, + "Shared Dirtied Blocks": 0, + "Shared Written Blocks": 0, + "Local Hit Blocks": 0, + "Local Read Blocks": 0, + "Local Dirtied Blocks": 0, + "Local Written Blocks": 0, + "Temp Read Blocks": 0, + "Temp Written Blocks": 0, + "Shared I/O Read Time": 0.000, + "Shared I/O Write Time": 0.000,+ "Local I/O Read Time": 0.000, + "Local I/O Write Time": 0.000, + "Temp I/O Read Time": 0.000, + "Temp I/O Write Time": 0.000, + "Memory Used": 22928, + "Memory Allocated": 32768 + } + } + ] (1 row) JSON format with planning time #explain (analyze, memory, buffers, format json) select * from pg_class; QUERY PLAN --------------------------------------- [ + { + "Plan": { + ... snip ... }, + "Planning": { + "Shared Hit Blocks": 152, + "Shared Read Blocks": 0, + "Shared Dirtied Blocks": 0, + "Shared Written Blocks": 0, + "Local Hit Blocks": 0, + "Local Read Blocks": 0, + "Local Dirtied Blocks": 0, + "Local Written Blocks": 0, + "Temp Read Blocks": 0, + "Temp Written Blocks": 0, + "Shared I/O Read Time": 0.000, + "Shared I/O Write Time": 0.000,+ "Local I/O Read Time": 0.000, + "Local I/O Write Time": 0.000, + "Temp I/O Read Time": 0.000, + "Temp I/O Write Time": 0.000, + "Memory Used": 22928, + "Memory Allocated": 32768 + }, + "Planning Time": 3.840, + "Triggers": [ + ], + "Execution Time": 1.266 + } + ] (1 row) > > How about separating those with ",". That would add a minor > inconsistency with how values in Buffers and I/O Timings sections are > reported. > did this way. -- Best Wishes, Ashutosh Bapat
From 402abed4d92df981400472dac86eb3cb2f92b06f Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat <ashutosh.ba...@enterprisedb.com> Date: Wed, 12 Jul 2023 14:34:14 +0530 Subject: [PATCH 1/2] EXPLAIN reports memory consumed for planning a query The memory consumed is reported as "Memory" property under "Planning" section in EXPLAIN output when option MEMORY is specified. A separate memory context is allocated for measuring memory consumption to eliminate any effect of previous activity on the calculation. The memory context statistics is noted before and after calling pg_plan_query() from ExplainOneQuery(). The difference in the two statistics is used to calculate the memory consumption. We report two values "used" and "allocated". The difference between memory statistics counters totalspace and freespace gives the memory that remains palloc'ed at the end of planning. It is reported as memory "used". This does not account for chunks of memory that were palloc'ed but subsequently pfree'ed. But such memory remains allocated in the memory context is given by the totalspace counter. The value of this counter is reported as memory "allocated". Author: Ashutosh Bapat Reviewed-by: David Rowley, Andrey Lepikhov, Jian He, Andy Fan Reviewed-by: Alvaro Herrera Discussion: https://www.postgresql.org/message-id/CAExHW5sZA=5lj_zppro-w09ck8z9p7eayaqq3ks9gdfhrxe...@mail.gmail.com --- contrib/auto_explain/auto_explain.c | 2 + doc/src/sgml/ref/explain.sgml | 14 ++++++ src/backend/commands/explain.c | 67 +++++++++++++++++++++++++- src/backend/commands/prepare.c | 29 +++++++++++- src/backend/utils/mmgr/mcxt.c | 13 +++++ src/include/commands/explain.h | 4 +- src/include/utils/memutils.h | 2 + src/test/regress/expected/explain.out | 68 +++++++++++++++++++++++++++ src/test/regress/sql/explain.sql | 6 +++ 9 files changed, 201 insertions(+), 4 deletions(-) diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index c3ac27ae99..26e80e4e16 100644 --- a/contrib/auto_explain/auto_explain.c +++ b/contrib/auto_explain/auto_explain.c @@ -396,6 +396,8 @@ explain_ExecutorEnd(QueryDesc *queryDesc) es->wal = (es->analyze && auto_explain_log_wal); es->timing = (es->analyze && auto_explain_log_timing); es->summary = es->analyze; + /* No support for MEMORY option */ + /* es->memory = false; */ es->format = auto_explain_log_format; es->settings = auto_explain_log_settings; diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index 5ba6486da1..26809d68d5 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -44,6 +44,7 @@ EXPLAIN [ ( <replaceable class="parameter">option</replaceable> [, ...] ) ] <rep WAL [ <replaceable class="parameter">boolean</replaceable> ] TIMING [ <replaceable class="parameter">boolean</replaceable> ] SUMMARY [ <replaceable class="parameter">boolean</replaceable> ] + MEMORY [ <replaceable class="parameter">boolean</replaceable> ] FORMAT { TEXT | XML | JSON | YAML } </synopsis> </refsynopsisdiv> @@ -250,6 +251,19 @@ ROLLBACK; </listitem> </varlistentry> + <varlistentry> + <term><literal>MEMORY</literal></term> + <listitem> + <para> + Include information on memory consumption by the query planning phase. + Specifically, include the precise amount of storage used by planner + in-memory structures, as well as total memory considering allocation + overhead. + The parameter defaults to <literal>FALSE</literal>. + </para> + </listitem> + </varlistentry> + <varlistentry> <term><literal>FORMAT</literal></term> <listitem> diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index f1d71bc54e..2fa93998a3 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -122,6 +122,8 @@ static const char *explain_get_index_name(Oid indexId); static void show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning); static void show_wal_usage(ExplainState *es, const WalUsage *usage); +static void show_planner_memory(ExplainState *es, + const MemoryContextCounters *mem_counts); static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir, ExplainState *es); static void ExplainScanTarget(Scan *plan, ExplainState *es); @@ -202,6 +204,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, summary_set = true; es->summary = defGetBoolean(opt); } + else if (strcmp(opt->defname, "memory") == 0) + es->memory = defGetBoolean(opt); else if (strcmp(opt->defname, "format") == 0) { char *p = defGetString(opt); @@ -397,6 +401,24 @@ ExplainOneQuery(Query *query, int cursorOptions, planduration; BufferUsage bufusage_start, bufusage; + MemoryContextCounters mem_counts; + MemoryContext planner_ctx = NULL; + MemoryContext saved_ctx = NULL; + + if (es->memory) + { + /* + * Create a new memory context to measure planner's memory + * consumption accurately. We should use the same type of memory + * context as the planner would use. That's usually AllocSet but + * ensure that. + */ + Assert(IsA(CurrentMemoryContext, AllocSetContext)); + planner_ctx = AllocSetContextCreate(CurrentMemoryContext, + "explain analyze planner context", + ALLOCSET_DEFAULT_SIZES); + saved_ctx = MemoryContextSwitchTo(planner_ctx); + } if (es->buffers) bufusage_start = pgBufferUsage; @@ -408,6 +430,12 @@ ExplainOneQuery(Query *query, int cursorOptions, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + if (es->memory) + { + MemoryContextSwitchTo(saved_ctx); + MemoryContextMemConsumed(planner_ctx, &mem_counts); + } + /* calc differences of buffer counters. */ if (es->buffers) { @@ -417,7 +445,8 @@ ExplainOneQuery(Query *query, int cursorOptions, /* run it (if needed) and produce output */ ExplainOnePlan(plan, into, es, queryString, params, queryEnv, - &planduration, (es->buffers ? &bufusage : NULL)); + &planduration, (es->buffers ? &bufusage : NULL), + (es->memory ? &mem_counts : NULL)); } } @@ -527,7 +556,8 @@ void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, const char *queryString, ParamListInfo params, QueryEnvironment *queryEnv, const instr_time *planduration, - const BufferUsage *bufusage) + const BufferUsage *bufusage, + const MemoryContextCounters *mem_counts) { DestReceiver *dest; QueryDesc *queryDesc; @@ -630,6 +660,13 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es); } + if (es->memory && mem_counts != NULL) + { + ExplainOpenGroup("Planner Memory", "Planner Memory", true, es); + show_planner_memory(es, mem_counts); + ExplainCloseGroup("Planner Memory", "Planner Memory", true, es); + } + /* Print info about runtime of triggers */ if (es->analyze) ExplainPrintTriggers(es, queryDesc); @@ -3766,6 +3803,32 @@ show_wal_usage(ExplainState *es, const WalUsage *usage) } } +/* + * Show planner's memory usage details. + */ +static void +show_planner_memory(ExplainState *es, + const MemoryContextCounters *mem_counts) +{ + if (es->format == EXPLAIN_FORMAT_TEXT) + { + appendStringInfo(es->str, + "Planner Memory: used=%lld bytes allocated=%lld bytes", + (long long) (mem_counts->totalspace - mem_counts->freespace), + (long long) mem_counts->totalspace); + appendStringInfoChar(es->str, '\n'); + } + else + { + ExplainPropertyInteger("Used", "bytes", + mem_counts->totalspace - mem_counts->freespace, + es); + ExplainPropertyInteger("Allocated", "bytes", + mem_counts->totalspace, es); + } +} + + /* * Add some additional details about an IndexScan or IndexOnlyScan */ diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c index 18f70319fc..e1577c791a 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -583,6 +583,26 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, instr_time planduration; BufferUsage bufusage_start, bufusage; + MemoryContextCounters mem_counts; + MemoryContext planner_ctx = NULL; + MemoryContext saved_ctx = NULL; + + if (es->memory) + { + /* + * In order to measure planner's memory consumption accurately, create + * a separate AllocSet memory context. + * + * XXX if planner is called under some other memory context type, this + * code overrides that. Do we need support to create context of + * programmatically determined type? + */ + Assert(IsA(CurrentMemoryContext, AllocSetContext)); + planner_ctx = AllocSetContextCreate(CurrentMemoryContext, + "explain analyze planner context", + ALLOCSET_DEFAULT_SIZES); + saved_ctx = MemoryContextSwitchTo(planner_ctx); + } if (es->buffers) bufusage_start = pgBufferUsage; @@ -624,6 +644,12 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); + if (es->memory) + { + MemoryContextSwitchTo(saved_ctx); + MemoryContextMemConsumed(planner_ctx, &mem_counts); + } + /* calc differences of buffer counters. */ if (es->buffers) { @@ -640,7 +666,8 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, if (pstmt->commandType != CMD_UTILITY) ExplainOnePlan(pstmt, into, es, query_string, paramLI, queryEnv, - &planduration, (es->buffers ? &bufusage : NULL)); + &planduration, (es->buffers ? &bufusage : NULL), + (es->memory ? &mem_counts : NULL)); else ExplainOneUtility(pstmt->utilityStmt, into, es, query_string, paramLI, queryEnv); diff --git a/src/backend/utils/mmgr/mcxt.c b/src/backend/utils/mmgr/mcxt.c index 4b30fcaebd..560af04dd7 100644 --- a/src/backend/utils/mmgr/mcxt.c +++ b/src/backend/utils/mmgr/mcxt.c @@ -687,6 +687,19 @@ MemoryContextMemAllocated(MemoryContext context, bool recurse) return total; } +/* + * Return the memory consumption statistics about the given context and its + * children. + */ +void +MemoryContextMemConsumed(MemoryContext context, + MemoryContextCounters *consumed) +{ + memset(consumed, 0, sizeof(*consumed)); + + MemoryContextStatsInternal(context, 0, false, 0, consumed, false); +} + /* * MemoryContextStats * Print statistics about the named context and all its descendants. diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index f9525fb572..798d1be2de 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -45,6 +45,7 @@ typedef struct ExplainState bool wal; /* print WAL usage */ bool timing; /* print detailed node timing */ bool summary; /* print total planning and execution timing */ + bool memory; /* print planner's memory usage information */ bool settings; /* print modified settings */ bool generic; /* generate a generic plan */ ExplainFormat format; /* output format */ @@ -92,7 +93,8 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, const char *queryString, ParamListInfo params, QueryEnvironment *queryEnv, const instr_time *planduration, - const BufferUsage *bufusage); + const BufferUsage *bufusage, + const MemoryContextCounters *mem_counts); extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc); extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc); diff --git a/src/include/utils/memutils.h b/src/include/utils/memutils.h index d14e8546a6..6f2abcfe4e 100644 --- a/src/include/utils/memutils.h +++ b/src/include/utils/memutils.h @@ -84,6 +84,8 @@ extern Size GetMemoryChunkSpace(void *pointer); extern MemoryContext MemoryContextGetParent(MemoryContext context); extern bool MemoryContextIsEmpty(MemoryContext context); extern Size MemoryContextMemAllocated(MemoryContext context, bool recurse); +extern void MemoryContextMemConsumed(MemoryContext context, + MemoryContextCounters *consumed); extern void MemoryContextStats(MemoryContext context); extern void MemoryContextStatsDetail(MemoryContext context, int max_children, bool print_to_stderr); diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index 809655e16e..86bfdfd29e 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -326,6 +326,74 @@ select explain_filter('explain (generic_plan) select unique1 from tenk1 where th select explain_filter('explain (analyze, generic_plan) select unique1 from tenk1 where thousand = $1'); ERROR: EXPLAIN options ANALYZE and GENERIC_PLAN cannot be used together CONTEXT: PL/pgSQL function explain_filter(text) line 5 at FOR over EXECUTE statement +-- MEMORY option +select explain_filter('explain (memory) select * from int8_tbl i8'); + explain_filter +--------------------------------------------------------- + Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N) + Planner Memory: used=N bytes allocated=N bytes +(2 rows) + +select explain_filter('explain (memory, analyze) select * from int8_tbl i8'); + explain_filter +----------------------------------------------------------------------------------------------- + Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N) + Planning Time: N.N ms + Planner Memory: used=N bytes allocated=N bytes + Execution Time: N.N ms +(4 rows) + +select explain_filter('explain (memory, summary, format yaml) select * from int8_tbl i8'); + explain_filter +------------------------------- + - Plan: + + Node Type: "Seq Scan" + + Parallel Aware: false + + Async Capable: false + + Relation Name: "int8_tbl"+ + Alias: "i8" + + Startup Cost: N.N + + Total Cost: N.N + + Plan Rows: N + + Plan Width: N + + Planning Time: N.N + + Planner Memory: + + Used: N + + Allocated: N +(1 row) + +select explain_filter('explain (memory, analyze, format json) select * from int8_tbl i8'); + explain_filter +------------------------------------ + [ + + { + + "Plan": { + + "Node Type": "Seq Scan", + + "Parallel Aware": false, + + "Async Capable": false, + + "Relation Name": "int8_tbl",+ + "Alias": "i8", + + "Startup Cost": N.N, + + "Total Cost": N.N, + + "Plan Rows": N, + + "Plan Width": N, + + "Actual Startup Time": N.N, + + "Actual Total Time": N.N, + + "Actual Rows": N, + + "Actual Loops": N + + }, + + "Planning Time": N.N, + + "Planner Memory": { + + "Used": N, + + "Allocated": N + + }, + + "Triggers": [ + + ], + + "Execution Time": N.N + + } + + ] +(1 row) + -- Test EXPLAIN (GENERIC_PLAN) with partition pruning -- partitions should be pruned at plan time, based on constants, -- but there should be no pruning based on parameter placeholders diff --git a/src/test/regress/sql/explain.sql b/src/test/regress/sql/explain.sql index b6b7beab27..f719e92f84 100644 --- a/src/test/regress/sql/explain.sql +++ b/src/test/regress/sql/explain.sql @@ -94,6 +94,12 @@ select explain_filter('explain (generic_plan) select unique1 from tenk1 where th -- should fail select explain_filter('explain (analyze, generic_plan) select unique1 from tenk1 where thousand = $1'); +-- MEMORY option +select explain_filter('explain (memory) select * from int8_tbl i8'); +select explain_filter('explain (memory, analyze) select * from int8_tbl i8'); +select explain_filter('explain (memory, summary, format yaml) select * from int8_tbl i8'); +select explain_filter('explain (memory, analyze, format json) select * from int8_tbl i8'); + -- Test EXPLAIN (GENERIC_PLAN) with partition pruning -- partitions should be pruned at plan time, based on constants, -- but there should be no pruning based on parameter placeholders -- 2.25.1
From 4637dd99b19bf8e3670a12850589aad235350a5a Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat <ashutosh.ba...@enterprisedb.com> Date: Thu, 18 Jan 2024 15:04:53 +0530 Subject: [PATCH 2/2] Use Planning section to report memory per Alvaro's comment Buffer usage during planning is reported under "Planning" section. Use the same section to report "Memory". Note to committer: This commit should be merged with the previous one before committing. Author: Ashutosh Bapat --- src/backend/commands/explain.c | 85 ++++++++++++++++++--------- src/test/regress/expected/explain.out | 20 +++---- 2 files changed, 68 insertions(+), 37 deletions(-) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 2fa93998a3..7e286f5020 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -119,11 +119,12 @@ static void show_instrumentation_count(const char *qlabel, int which, static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es); static void show_eval_params(Bitmapset *bms_params, ExplainState *es); static const char *explain_get_index_name(Oid indexId); -static void show_buffer_usage(ExplainState *es, const BufferUsage *usage, +static bool show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning); static void show_wal_usage(ExplainState *es, const WalUsage *usage); -static void show_planner_memory(ExplainState *es, - const MemoryContextCounters *mem_counts); +static bool show_planner_memory(ExplainState *es, + const MemoryContextCounters *mem_counts, + bool show_planning); static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir, ExplainState *es); static void ExplainScanTarget(Scan *plan, ExplainState *es); @@ -645,11 +646,22 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, /* Create textual dump of plan tree */ ExplainPrintPlan(es, queryDesc); - /* Show buffer usage in planning */ - if (bufusage) + /* Show buffer and/or memory usage in planning */ + if (bufusage || mem_counts) { + bool showed_planning = false; + ExplainOpenGroup("Planning", "Planning", true, es); - show_buffer_usage(es, bufusage, true); + + if (bufusage) + showed_planning = show_buffer_usage(es, bufusage, true); + + if (mem_counts) + showed_planning |= show_planner_memory(es, mem_counts, !showed_planning); + + if (showed_planning) + es->indent--; + ExplainCloseGroup("Planning", "Planning", true, es); } @@ -660,13 +672,6 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es); } - if (es->memory && mem_counts != NULL) - { - ExplainOpenGroup("Planner Memory", "Planner Memory", true, es); - show_planner_memory(es, mem_counts); - ExplainCloseGroup("Planner Memory", "Planner Memory", true, es); - } - /* Print info about runtime of triggers */ if (es->analyze) ExplainPrintTriggers(es, queryDesc); @@ -3583,10 +3588,20 @@ explain_get_index_name(Oid indexId) /* * Show buffer usage details. + * + * When reporting in TEXT format this function opens "planning" section if only there are counts to + * be reported for planning. The function returns true if the section was + * opened, false otherwise. The function does not close the section. The caller is expected to use the return value to + * close the section if required. + * + * When reporting in non-TEXT format the caller is expected to open and close the section, + * if required. Hence the function always returns false for non-TEXT formats. */ -static void +static bool show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) { + bool show_planning = false; + if (es->format == EXPLAIN_FORMAT_TEXT) { bool has_shared = (usage->shared_blks_hit > 0 || @@ -3605,12 +3620,10 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) !INSTR_TIME_IS_ZERO(usage->local_blk_write_time)); bool has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) || !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time)); - bool show_planning = (planning && (has_shared || - has_local || has_temp || - has_shared_timing || - has_local_timing || - has_temp_timing)); + show_planning = (planning && (has_shared || has_local || has_temp || + has_shared_timing || has_local_timing || + has_temp_timing)); if (show_planning) { ExplainIndentText(es); @@ -3715,9 +3728,6 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) } appendStringInfoChar(es->str, '\n'); } - - if (show_planning) - es->indent--; } else { @@ -3763,6 +3773,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) 3, es); } } + + return show_planning; } /* @@ -3805,27 +3817,46 @@ show_wal_usage(ExplainState *es, const WalUsage *usage) /* * Show planner's memory usage details. + * + * When reporting in TEXT format this function opens the "planning" section if only it was not opened already. The function returns true if it opened the section, + * false otherwise. The caller is expected to use the return value to + * close the section if required. + * + * When reporting in non-TEXT format the caller is expected to open and close the section, + * if required. Hence the function always returns false for non-TEXT formats. */ -static void +static bool show_planner_memory(ExplainState *es, - const MemoryContextCounters *mem_counts) + const MemoryContextCounters *mem_counts, bool show_planning) { if (es->format == EXPLAIN_FORMAT_TEXT) { + if (show_planning) + { + ExplainIndentText(es); + appendStringInfoString(es->str, "Planning:\n"); + es->indent++; + } + + ExplainIndentText(es); appendStringInfo(es->str, - "Planner Memory: used=%lld bytes allocated=%lld bytes", + "Memory: used=%lld bytes, allocated=%lld bytes", (long long) (mem_counts->totalspace - mem_counts->freespace), (long long) mem_counts->totalspace); appendStringInfoChar(es->str, '\n'); } else { - ExplainPropertyInteger("Used", "bytes", + show_planning = false; + + ExplainPropertyInteger("Memory Used", "bytes", mem_counts->totalspace - mem_counts->freespace, es); - ExplainPropertyInteger("Allocated", "bytes", + ExplainPropertyInteger("Memory Allocated", "bytes", mem_counts->totalspace, es); } + + return show_planning; } diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index 86bfdfd29e..55694505a7 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -331,15 +331,15 @@ select explain_filter('explain (memory) select * from int8_tbl i8'); explain_filter --------------------------------------------------------- Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N) - Planner Memory: used=N bytes allocated=N bytes + Memory: used=N bytes, allocated=N bytes (2 rows) select explain_filter('explain (memory, analyze) select * from int8_tbl i8'); explain_filter ----------------------------------------------------------------------------------------------- Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N) + Memory: used=N bytes, allocated=N bytes Planning Time: N.N ms - Planner Memory: used=N bytes allocated=N bytes Execution Time: N.N ms (4 rows) @@ -356,10 +356,10 @@ select explain_filter('explain (memory, summary, format yaml) select * from int8 Total Cost: N.N + Plan Rows: N + Plan Width: N + - Planning Time: N.N + - Planner Memory: + - Used: N + - Allocated: N + Planning: + + Memory Used: N + + Memory Allocated: N + + Planning Time: N.N (1 row) select explain_filter('explain (memory, analyze, format json) select * from int8_tbl i8'); @@ -382,11 +382,11 @@ select explain_filter('explain (memory, analyze, format json) select * from int8 "Actual Rows": N, + "Actual Loops": N + }, + - "Planning Time": N.N, + - "Planner Memory": { + - "Used": N, + - "Allocated": N + + "Planning": { + + "Memory Used": N, + + "Memory Allocated": N + }, + + "Planning Time": N.N, + "Triggers": [ + ], + "Execution Time": N.N + -- 2.25.1