diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index c7aacd7812..677c135f59 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 */ + /* 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..a4b6564bdb 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -44,6 +44,7 @@ EXPLAIN [ ( option [, ...] ) ] boolean ] TIMING [ boolean ] SUMMARY [ boolean ] + MEMORY [ boolean ] FORMAT { TEXT | XML | JSON | YAML } @@ -250,6 +251,19 @@ ROLLBACK; + + MEMORY + + + 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. + This parameter defaults to FALSE. + + + + FORMAT diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 843472e6dd..83d00a4663 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -119,9 +119,11 @@ 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, - bool planning); +static bool peek_buffer_usage(ExplainState *es, const BufferUsage *usage); +static void show_buffer_usage(ExplainState *es, const BufferUsage *usage); static void show_wal_usage(ExplainState *es, const WalUsage *usage); +static void show_memory_counters(ExplainState *es, + const MemoryContextCounters *mem_counters); 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,25 @@ ExplainOneQuery(Query *query, int cursorOptions, planduration; BufferUsage bufusage_start, bufusage; + MemoryContextCounters mem_counters; + MemoryContext planner_ctx = NULL; + MemoryContext saved_ctx = NULL; + + if (es->memory) + { + /* + * Create a new memory context to measure planner's memory + * consumption accurately. Note that if the planner were to be + * modified to use a different memory context type, here we would + * be changing that to AllocSet, which might be undesirable. + * However, we don't have a way to create a context of the same + * type as another, so we pray and hope that this is OK. + */ + planner_ctx = AllocSetContextCreate(CurrentMemoryContext, + "explain analyze planner context", + ALLOCSET_DEFAULT_SIZES); + saved_ctx = MemoryContextSwitchTo(planner_ctx); + } if (es->buffers) bufusage_start = pgBufferUsage; @@ -408,6 +431,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_counters); + } + /* calc differences of buffer counters. */ if (es->buffers) { @@ -417,7 +446,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_counters : NULL); } } @@ -527,7 +557,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_counters) { DestReceiver *dest; QueryDesc *queryDesc; @@ -615,11 +646,27 @@ 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 (peek_buffer_usage(es, bufusage) || mem_counters) { ExplainOpenGroup("Planning", "Planning", true, es); - show_buffer_usage(es, bufusage, true); + + if (es->format == EXPLAIN_FORMAT_TEXT) + { + ExplainIndentText(es); + appendStringInfoString(es->str, "Planning:\n"); + es->indent++; + } + + if (bufusage) + show_buffer_usage(es, bufusage); + + if (mem_counters) + show_memory_counters(es, mem_counters); + + if (es->format == EXPLAIN_FORMAT_TEXT) + es->indent--; + ExplainCloseGroup("Planning", "Planning", true, es); } @@ -2106,7 +2153,7 @@ ExplainNode(PlanState *planstate, List *ancestors, /* Show buffer/WAL usage */ if (es->buffers && planstate->instrument) - show_buffer_usage(es, &planstate->instrument->bufusage, false); + show_buffer_usage(es, &planstate->instrument->bufusage); if (es->wal && planstate->instrument) show_wal_usage(es, &planstate->instrument->walusage); @@ -2125,7 +2172,7 @@ ExplainNode(PlanState *planstate, List *ancestors, ExplainOpenWorker(n, es); if (es->buffers) - show_buffer_usage(es, &instrument->bufusage, false); + show_buffer_usage(es, &instrument->bufusage); if (es->wal) show_wal_usage(es, &instrument->walusage); ExplainCloseWorker(n, es); @@ -3545,10 +3592,52 @@ explain_get_index_name(Oid indexId) } /* - * Show buffer usage details. + * Return whether show_buffer_usage would have anything to print, if given + * the same 'usage' data. Note that when the format is anything other than + * text, we print even if the counters are all zeroes. + */ +static bool +peek_buffer_usage(ExplainState *es, const BufferUsage *usage) +{ + bool has_shared; + bool has_local; + bool has_temp; + bool has_shared_timing; + bool has_local_timing; + bool has_temp_timing; + + if (usage == NULL) + return false; + + if (es->format != EXPLAIN_FORMAT_TEXT) + return true; + + has_shared = (usage->shared_blks_hit > 0 || + usage->shared_blks_read > 0 || + usage->shared_blks_dirtied > 0 || + usage->shared_blks_written > 0); + has_local = (usage->local_blks_hit > 0 || + usage->local_blks_read > 0 || + usage->local_blks_dirtied > 0 || + usage->local_blks_written > 0); + has_temp = (usage->temp_blks_read > 0 || + usage->temp_blks_written > 0); + has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) || + !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time)); + has_local_timing = (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time) || + !INSTR_TIME_IS_ZERO(usage->local_blk_write_time)); + has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) || + !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time)); + + return has_shared || has_local || has_temp || has_shared_timing || + has_local_timing || has_temp_timing; +} + +/* + * Show buffer usage details. This better be sync with peek_buffer_usage. */ static void -show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) +show_buffer_usage(ExplainState *es, const BufferUsage *usage) { if (es->format == EXPLAIN_FORMAT_TEXT) { @@ -3568,18 +3657,6 @@ 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)); - - if (show_planning) - { - ExplainIndentText(es); - appendStringInfoString(es->str, "Planning:\n"); - es->indent++; - } /* Show only positive counter values. */ if (has_shared || has_local || has_temp) @@ -3678,9 +3755,6 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) } appendStringInfoChar(es->str, '\n'); } - - if (show_planning) - es->indent--; } else { @@ -3766,6 +3840,32 @@ show_wal_usage(ExplainState *es, const WalUsage *usage) } } +/* + * Show memory usage details. + */ +static void +show_memory_counters(ExplainState *es, const MemoryContextCounters *mem_counters) +{ + if (es->format == EXPLAIN_FORMAT_TEXT) + { + ExplainIndentText(es); + appendStringInfo(es->str, + "Memory: used=%lld bytes allocated=%lld bytes", + (long long) (mem_counters->totalspace - mem_counters->freespace), + (long long) mem_counters->totalspace); + appendStringInfoChar(es->str, '\n'); + } + else + { + ExplainPropertyInteger("Memory Used", "bytes", + mem_counters->totalspace - mem_counters->freespace, + es); + ExplainPropertyInteger("Memory Allocated", "bytes", + mem_counters->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 703976f633..bf1579d36d 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -583,6 +583,19 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, instr_time planduration; BufferUsage bufusage_start, bufusage; + MemoryContextCounters mem_counters; + MemoryContext planner_ctx = NULL; + MemoryContext saved_ctx = NULL; + + if (es->memory) + { + /* See ExplainOneQuery about this */ + 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 +637,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_counters); + } + /* calc differences of buffer counters. */ if (es->buffers) { @@ -640,7 +659,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_counters : 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 1336944084..ad7409a02c 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 1b44d483d6..7c0f0b5636 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_counters); 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 ca7858d6b6..7fd41d20ca 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..1299ee79ad 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -326,6 +326,82 @@ 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) + 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 + 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: + + 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'); + 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": { + + "Memory Used": N, + + "Memory Allocated": N + + }, + + "Planning Time": N.N, + + "Triggers": [ + + ], + + "Execution Time": N.N + + } + + ] +(1 row) + +prepare int8_query as select * from int8_tbl i8; +select explain_filter('explain (memory) execute int8_query'); + explain_filter +--------------------------------------------------------- + Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N) + Memory: used=N bytes allocated=N bytes +(2 rows) + -- 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..2274dc1b5a 100644 --- a/src/test/regress/sql/explain.sql +++ b/src/test/regress/sql/explain.sql @@ -94,6 +94,14 @@ 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'); +prepare int8_query as select * from int8_tbl i8; +select explain_filter('explain (memory) execute int8_query'); + -- 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