Hi Alvaro,
Thanks for the review and the edits. Sorry for replying late.
On Tue, Nov 21, 2023 at 11:56 PM Alvaro Herrera <alvhe...@alvh.no-ip.org> wrote:
>
> I gave this a quick look. I think the usefulness aspect is already
> established in general terms; the bit I'm not so sure about is whether
> we want it enabled by default. For many cases it'd just be noise.
> Perhaps we want it hidden behind something like "EXPLAIN (MEMORY)" or
> such, particularly since things like "allocated" (which, per David,
> seems to be the really useful metric) seems too much a PG-developer
> value rather than an end-user value.
It is not default but hidden behind "SUMMARY".Do you still think it
requires another sub-flag MEMORY?
>
> If EXPLAIN (MEMORY) is added, then probably auto_explain needs a
> corresponding flag, and doc updates.
>
> Some code looks to be in weird places. Why is calc_mem_usage, which
> operates on MemoryContextCounters, in explain.c instead of mcxt.c?
> why is MemUsage in explain.h instead of memnodes.h? I moved both. I
> also renamed them, to MemoryContextSizeDifference() and MemoryUsage
> respectively; fixup patch attached.
That looks better. The functions are now available outside explain.
>
> I see no reason for this to be three separate patches anymore.
Squashed into one along with your changes.
>
> The EXPLAIN docs (explain.sgml) need an update to mention the new flag
> and the new output, too.
Updated section describing "SUMMARY" flag.
PFA updated patch.
--
Best Wishes,
Ashutosh Bapat
From e38cde855a8aaaf77b9a01c948db7cde106993a6 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] EXPLAIN reports memory consumed for planning a query
The memory consumed is reported as "Planner Memory" property in EXPLAIN
output when any of the options ANALYZE or SUMMARY 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".
Ashutosh Bapat, reviewed by David Rowley and Alvaro Herrera
---
doc/src/sgml/ref/explain.sgml | 8 +++-
src/backend/commands/explain.c | 55 ++++++++++++++++++++++++++-
src/backend/commands/prepare.c | 24 +++++++++++-
src/backend/utils/mmgr/mcxt.c | 38 ++++++++++++++++++
src/include/commands/explain.h | 3 +-
src/include/nodes/memnodes.h | 10 +++++
src/include/utils/memutils.h | 5 +++
src/test/regress/expected/explain.out | 26 +++++++++++--
src/tools/pgindent/typedefs.list | 1 +
9 files changed, 160 insertions(+), 10 deletions(-)
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 5ba6486da1..ba33e9be2d 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -239,8 +239,12 @@ ROLLBACK;
<term><literal>SUMMARY</literal></term>
<listitem>
<para>
- Include summary information (e.g., totaled timing information) after the
- query plan. Summary information is included by default when
+ Include summary information after the query plan. The summary information
+ includes the totaled timing information and planner's memory consumption.
+ The memory consumption is reported as two values "used" and "allocated".
+ "used" indicates the net memory used by the planner. The "allocated"
+ indicates the memory allocated, which may slightly higher than the memory
+ used, by the planner. Summary information is included by default when
<literal>ANALYZE</literal> is used but otherwise is not included by
default, but can be enabled using this option. Planning time in
<command>EXPLAIN EXECUTE</command> includes the time required to fetch
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index f1d71bc54e..8c7f27b661 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_planning_memory(ExplainState *es,
+ const MemoryUsage *usage);
static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
ExplainState *es);
static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -393,13 +395,30 @@ ExplainOneQuery(Query *query, int cursorOptions,
else
{
PlannedStmt *plan;
+ MemoryContext planner_ctx;
instr_time planstart,
planduration;
BufferUsage bufusage_start,
bufusage;
+ MemoryContextCounters mem_counts_start;
+ MemoryContextCounters mem_counts_end;
+ MemoryUsage mem_usage;
+ MemoryContext saved_ctx;
+ /*
+ * Create a new memory context to accurately measure memory malloc'ed
+ * by the planner. For further accuracy 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);
if (es->buffers)
bufusage_start = pgBufferUsage;
+ MemoryContextMemConsumed(planner_ctx, &mem_counts_start);
+ saved_ctx = MemoryContextSwitchTo(planner_ctx);
INSTR_TIME_SET_CURRENT(planstart);
/* plan the query */
@@ -407,6 +426,9 @@ ExplainOneQuery(Query *query, int cursorOptions,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
+ MemoryContextSwitchTo(saved_ctx);
+ MemoryContextMemConsumed(planner_ctx, &mem_counts_end);
+ MemoryContextSizeDifference(&mem_usage, &mem_counts_start, &mem_counts_end);
/* calc differences of buffer counters. */
if (es->buffers)
@@ -417,7 +439,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),
+ &mem_usage);
}
}
@@ -527,7 +550,7 @@ 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 MemoryUsage *mem_usage)
{
DestReceiver *dest;
QueryDesc *queryDesc;
@@ -630,6 +653,13 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
}
+ if (es->summary && mem_usage)
+ {
+ ExplainOpenGroup("Planner Memory", "Planner Memory", true, es);
+ show_planning_memory(es, mem_usage);
+ ExplainCloseGroup("Planner Memory", "Planner Memory", true, es);
+ }
+
/* Print info about runtime of triggers */
if (es->analyze)
ExplainPrintTriggers(es, queryDesc);
@@ -3766,6 +3796,27 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
}
}
+/*
+ * Show planner's memory usage details.
+ */
+static void
+show_planning_memory(ExplainState *es, const MemoryUsage *usage)
+{
+ if (es->format == EXPLAIN_FORMAT_TEXT)
+ {
+ appendStringInfo(es->str,
+ "Planner Memory: used=%zu bytes allocated=%zu bytes",
+ usage->bytes_used, usage->bytes_allocated);
+ appendStringInfoChar(es->str, '\n');
+ }
+ else
+ {
+ ExplainPropertyInteger("Used", "bytes", usage->bytes_used, es);
+ ExplainPropertyInteger("Allocated", "bytes", usage->bytes_allocated, 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..3d3d0ae6a3 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -583,9 +583,27 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
instr_time planduration;
BufferUsage bufusage_start,
bufusage;
+ MemoryContextCounters mem_counts_start;
+ MemoryContextCounters mem_counts_end;
+ MemoryUsage mem_usage;
+ MemoryContext planner_ctx;
+ MemoryContext saved_ctx;
+
+ /*
+ * Create a new memory context to accurately measure memory malloc'ed by
+ * the planner. For further accuracy 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);
if (es->buffers)
bufusage_start = pgBufferUsage;
+ MemoryContextMemConsumed(planner_ctx, &mem_counts_start);
+ saved_ctx = MemoryContextSwitchTo(planner_ctx);
INSTR_TIME_SET_CURRENT(planstart);
/* Look it up in the hash table */
@@ -623,6 +641,9 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
+ MemoryContextSwitchTo(saved_ctx);
+ MemoryContextMemConsumed(planner_ctx, &mem_counts_end);
+ MemoryContextSizeDifference(&mem_usage, &mem_counts_start, &mem_counts_end);
/* calc differences of buffer counters. */
if (es->buffers)
@@ -640,7 +661,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),
+ &mem_usage);
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 9fc83f11f6..28e5f36405 100644
--- a/src/backend/utils/mmgr/mcxt.c
+++ b/src/backend/utils/mmgr/mcxt.c
@@ -687,6 +687,32 @@ MemoryContextMemAllocated(MemoryContext context, bool recurse)
return total;
}
+/*
+ * Compute memory usage from the start and end memory counts.
+ */
+void
+MemoryContextSizeDifference(MemoryUsage *mem_usage,
+ MemoryContextCounters *start,
+ MemoryContextCounters *end)
+{
+ /*
+ * We compute the memory "used" as the difference, between end situation
+ * and start situation, of the memory that's allocated according to the
+ * counters, excluding memory in freelists.
+ */
+ mem_usage->bytes_used =
+ (end->totalspace - end->freespace) -
+ (start->totalspace - start->freespace);
+
+ /*
+ * The net memory used is from total memory allocated and not necessarily
+ * the net memory allocated between the two given samples. Hence do not
+ * compute the difference between allocated memory reported in the two
+ * given samples.
+ */
+ mem_usage->bytes_allocated = end->totalspace;
+}
+
/*
* MemoryContextStats
* Print statistics about the named context and all its descendants.
@@ -747,6 +773,18 @@ MemoryContextStatsDetail(MemoryContext context, int max_children,
grand_totals.totalspace - grand_totals.freespace)));
}
+/*
+ * Return the memory used in the given context and its children.
+ */
+extern void
+MemoryContextMemConsumed(MemoryContext context,
+ MemoryContextCounters *consumed)
+{
+ memset(consumed, 0, sizeof(*consumed));
+
+ MemoryContextStatsInternal(context, 0, false, 0, consumed, false);
+}
+
/*
* MemoryContextStatsInternal
* One recursion level for MemoryContextStats
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index f9525fb572..6947cbae8b 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -92,7 +92,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 MemoryUsage *mem_usage);
extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc);
extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc);
diff --git a/src/include/nodes/memnodes.h b/src/include/nodes/memnodes.h
index ff6453bb7a..577d39cef4 100644
--- a/src/include/nodes/memnodes.h
+++ b/src/include/nodes/memnodes.h
@@ -34,6 +34,16 @@ typedef struct MemoryContextCounters
Size freespace; /* The unused portion of totalspace */
} MemoryContextCounters;
+/*
+ * MemoryUsage
+ * For concise reporting of memory consumption
+ */
+typedef struct MemoryUsage
+{
+ Size bytes_used;
+ Size bytes_allocated;
+} MemoryUsage;
+
/*
* MemoryContext
* A logical context in which memory allocations occur.
diff --git a/src/include/utils/memutils.h b/src/include/utils/memutils.h
index d14e8546a6..24dc0e996e 100644
--- a/src/include/utils/memutils.h
+++ b/src/include/utils/memutils.h
@@ -84,6 +84,11 @@ 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 MemoryContextSizeDifference(MemoryUsage *mem_usage,
+ MemoryContextCounters *start,
+ MemoryContextCounters *end);
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..48e4ad1c3f 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -65,8 +65,9 @@ select explain_filter('explain (analyze) select * from int8_tbl i8');
-----------------------------------------------------------------------------------------------
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
-(3 rows)
+(4 rows)
select explain_filter('explain (analyze, verbose) select * from int8_tbl i8');
explain_filter
@@ -74,16 +75,18 @@ select explain_filter('explain (analyze, verbose) select * from int8_tbl i8');
Seq Scan on public.int8_tbl i8 (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N)
Output: q1, q2
Planning Time: N.N ms
+ Planner Memory: used=N bytes allocated=N bytes
Execution Time: N.N ms
-(4 rows)
+(5 rows)
select explain_filter('explain (analyze, buffers, format text) 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
-(3 rows)
+(4 rows)
select explain_filter('explain (analyze, buffers, format xml) select * from int8_tbl i8');
explain_filter
@@ -128,6 +131,10 @@ select explain_filter('explain (analyze, buffers, format xml) select * from int8
<Temp-Written-Blocks>N</Temp-Written-Blocks> +
</Planning> +
<Planning-Time>N.N</Planning-Time> +
+ <Planner-Memory> +
+ <Used>N</Used> +
+ <Allocated>N</Allocated> +
+ </Planner-Memory> +
<Triggers> +
</Triggers> +
<Execution-Time>N.N</Execution-Time> +
@@ -174,6 +181,9 @@ select explain_filter('explain (analyze, buffers, format yaml) select * from int
Temp Read Blocks: N +
Temp Written Blocks: N +
Planning Time: N.N +
+ Planner Memory: +
+ Used: N +
+ Allocated: N +
Triggers: +
Execution Time: N.N
(1 row)
@@ -284,6 +294,10 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
"Temp I/O Write Time": N.N +
}, +
"Planning Time": N.N, +
+ "Planner Memory": { +
+ "Used": N, +
+ "Allocated": N +
+ }, +
"Triggers": [ +
], +
"Execution Time": N.N +
@@ -535,7 +549,11 @@ select jsonb_pretty(
"Triggers": [ +
], +
"Planning Time": 0.0, +
- "Execution Time": 0.0 +
+ "Execution Time": 0.0, +
+ "Planner Memory": { +
+ "Used": 0, +
+ "Allocated": 0 +
+ } +
} +
]
(1 row)
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index d659adbfd6..0691135b67 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1554,6 +1554,7 @@ MemoryContextData
MemoryContextMethodID
MemoryContextMethods
MemoryStatsPrintFunc
+MemoryUsage
MergeAction
MergeActionState
MergeAppend
--
2.25.1
