Sorry for the late reply. I was working on David's suggestion. Here's a response to your questions and also a new set of patches.
On Tue, Aug 22, 2023 at 1:16 PM jian he <jian.universal...@gmail.com> wrote:
> Hi. I tested it.
> not sure if following is desired behavior. first run with explain,
> then run with explain(summary on).
> the second time, Planning Memory: 0 bytes.
>
> regression=# PREPARE q4 AS SELECT 1 AS a;
> explain EXECUTE q4;
> QUERY PLAN
> ------------------------------------------
> Result (cost=0.00..0.01 rows=1 width=4)
> (1 row)
>
> regression=# explain(summary on) EXECUTE q4;
> QUERY PLAN
> ------------------------------------------
> Result (cost=0.00..0.01 rows=1 width=4)
> Planning Time: 0.009 ms
> Planning Memory: 0 bytes
> (3 rows)
> ---------------------------------------------
Yes. This is expected since the plan is already available and no
memory is required to fetch it from the cache. I imagine, if there
were parameters to the prepared plan, it would consume some memory to
evaluate those parameters and some more memory if replanning was
required.
> previously, if you want stats of a given memory context and its
> children, you can only use MemoryContextStatsDetail.
> but it will only go to stderr or LOG_SERVER_ONLY.
> Now, MemoryContextMemUsed is being exposed. I can do something like:
>
> mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
> //do stuff.
> mem_consumed = MemoryContextMemUsed(CurrentMemoryContext) - mem_consumed;
>
> it will give me the NET memory consumed by doing staff in between. Is
> my understanding correct?
Yes.
Here are three patches based on the latest master.
0001
====
this is same as the previous patch with few things fixed. 1. Call
MemoryContextMemUsed() before INSTR_TIME_SET_CURRENT so that the time
taken by MemoryContextMemUsed() is not counted in planning time. 2. In
ExplainOnePlan, use a separate code block for reporting memory.
0002
====
This patch reports both memory allocated and memory used in the
CurrentMemoryContext at the time of planning. It converts "Planning
Memory" into a section with two values reported as "used" and
"allocated" as below
#explain (summary on) select * from pg_class c, pg_type t where
c.reltype = t.oid;
QUERY PLAN
--------------------------------------------------------------------------
Hash Join (cost=28.84..47.08 rows=414 width=533)
... snip ...
Planning Time: 9.274 ms
Planning Memory: used=80848 bytes allocated=90112 bytes
(7 rows)
In JSON format
#explain (summary on, format json) select * from pg_class c, pg_type t
where c.reltype = t.oid;
QUERY PLAN
-----------------------------------------------
[ +
{ +
"Plan": { +
... snip ...
}, +
"Planning Time": 0.466, +
"Planning Memory": { +
"Used": 80608, +
"Allocated": 90112 +
} +
} +
]
(1 row)
PFA explain and explain analyze output in all the formats.
The patch adds MemoryContextMemConsumed() which is similar to
MemoryContextStats() or MemoryContextStatsDetails() except 1. the
later always prints the memory statistics to either stderr or to the
server error log and 2. it doesn't return MemoryContextCounters that
it gathered. We should probably change MemoryContextStats or
MemoryContextStatsDetails() according to those two points and not add
MemoryContextMemConsumed().
I have not merged this into 0001 yet. But once we agree upon whether
this is the right thing to do, I will merge it into 0001.
0003
====
When reporting memory allocated, a confusion may arise as to whether
to report the "net" memory allocated between start and end of planner
OR only the memory that remains allocated after end. This confusion
can be avoided by using an exclusive memory context (child of
CurrentMemoryContext) for planning. That's what 0003 implements as
suggested by David. As mentioned in one of the comments in the patch,
in order to measure memory allocated accurately the new MemoryContext
has to be of the same type as the memory context that will be used
otherwise by the planner i.e. CurrentMemoryContext, and should use the
same parameters. IIUC, it will always be AllocSet. So the patch uses
AllocSet and Asserts so. But in case this changes in future, we will
need a way to create a new memory context with the same properties as
the CurrentMemoryContext, a functionality missing right now. Once we
agree upon the approach, the patch will need to be merged into 0002
and in turn 0001.
--
Best Wishes,
Ashutosh Bapat
explain_planning_memory.out
Description: Binary data
From eaada36e47f914e44889e519dc377e6272b96c40 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.ba...@enterprisedb.com>
Date: Wed, 23 Aug 2023 16:23:12 +0530
Subject: [PATCH 2/3] Report memory allocated along with memory used in EXPLAIN
Memory might be pallc'ed and pfree'ed during planning. The memory used at the
end of planning may miss a large chunk of memory palloc'ed and pfree'ed during
planning. But the corresponding memory may remain allocated in the memory
context. Hence report both memory used and memory allocated to detect any such
activity during planning.
Ashutosh Bapat, per suggestion by David Rowley
---
src/backend/commands/explain.c | 69 +++++++++++++++++++++++----
src/backend/commands/prepare.c | 12 +++--
src/backend/utils/mmgr/mcxt.c | 13 ++---
src/include/commands/explain.h | 11 ++++-
src/include/utils/memutils.h | 3 +-
src/test/regress/expected/explain.out | 25 +++++++---
6 files changed, 102 insertions(+), 31 deletions(-)
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 7891b70c53..b014d6be7f 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 MemUsage *usage);
static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
ExplainState *es);
static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -397,11 +399,13 @@ ExplainOneQuery(Query *query, int cursorOptions,
planduration;
BufferUsage bufusage_start,
bufusage;
- Size mem_consumed;
+ MemoryContextCounters mem_counts_start;
+ MemoryContextCounters mem_counts_end;
+ MemUsage mem_usage;
if (es->buffers)
bufusage_start = pgBufferUsage;
- mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
+ MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_start);
INSTR_TIME_SET_CURRENT(planstart);
/* plan the query */
@@ -409,8 +413,8 @@ ExplainOneQuery(Query *query, int cursorOptions,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
- mem_consumed = MemoryContextMemUsed(CurrentMemoryContext)
- - mem_consumed;
+ MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_end);
+ calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start);
/* calc differences of buffer counters. */
if (es->buffers)
@@ -422,7 +426,7 @@ ExplainOneQuery(Query *query, int cursorOptions,
/* run it (if needed) and produce output */
ExplainOnePlan(plan, into, es, queryString, params, queryEnv,
&planduration, (es->buffers ? &bufusage : NULL),
- &mem_consumed);
+ &mem_usage);
}
}
@@ -532,7 +536,7 @@ void
ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
const char *queryString, ParamListInfo params,
QueryEnvironment *queryEnv, const instr_time *planduration,
- const BufferUsage *bufusage, const Size *mem_consumed)
+ const BufferUsage *bufusage, const MemUsage *mem_usage)
{
DestReceiver *dest;
QueryDesc *queryDesc;
@@ -635,9 +639,12 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
}
- if (es->summary && mem_consumed)
- ExplainPropertyUInteger("Planning Memory", "bytes",
- (uint64) *mem_consumed, es);
+ if (es->summary && mem_usage)
+ {
+ ExplainOpenGroup("Planning Memory", "Planning Memory", true, es);
+ show_planning_memory(es, mem_usage);
+ ExplainCloseGroup("Planning Memory", "Planning Memory", true, es);
+ }
/* Print info about runtime of triggers */
if (es->analyze)
@@ -3745,6 +3752,50 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
}
}
+/*
+ * Show planner's memory usage details.
+ */
+static void
+show_planning_memory(ExplainState *es, const MemUsage *usage)
+{
+ if (es->format == EXPLAIN_FORMAT_TEXT)
+ {
+ appendStringInfo(es->str,
+ "Planning Memory: used=%zu bytes allocated=%zu bytes",
+ usage->mem_used, usage->mem_allocated);
+ appendStringInfoChar(es->str, '\n');
+ }
+ else
+ {
+ ExplainPropertyInteger("Used", "bytes", usage->mem_used, es);
+ ExplainPropertyInteger("Allocated", "bytes", usage->mem_allocated, es);
+ }
+}
+
+/*
+ * Compute memory usage from the start and end memory counts.
+ */
+void
+calc_mem_usage(MemUsage *mem_usage, MemoryContextCounters *mem_counts_end,
+ MemoryContextCounters *mem_counts_start)
+{
+ Size mem_used_start;
+ Size mem_used_end;
+
+ mem_used_start = mem_counts_start->totalspace - mem_counts_start->freespace;
+ mem_used_end = mem_counts_end->totalspace - mem_counts_end->freespace;
+
+ mem_usage->mem_used = mem_used_end - mem_used_start;
+
+ /*
+ * 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->mem_allocated = mem_counts_end->totalspace;
+}
+
/*
* Add some additional details about an IndexScan or IndexOnlyScan
*/
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index ccae1b4477..ebc0d47ba9 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -583,11 +583,13 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
instr_time planduration;
BufferUsage bufusage_start,
bufusage;
- Size mem_consumed;
+ MemoryContextCounters mem_counts_start;
+ MemoryContextCounters mem_counts_end;
+ MemUsage mem_usage;
if (es->buffers)
bufusage_start = pgBufferUsage;
- mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
+ MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_start);
INSTR_TIME_SET_CURRENT(planstart);
/* Look it up in the hash table */
@@ -625,8 +627,8 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
- mem_consumed = MemoryContextMemUsed(CurrentMemoryContext)
- - mem_consumed;
+ MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_end);
+ calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start);
/* calc differences of buffer counters. */
if (es->buffers)
@@ -645,7 +647,7 @@ 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),
- &mem_consumed);
+ &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 1ea966b186..94159a6799 100644
--- a/src/backend/utils/mmgr/mcxt.c
+++ b/src/backend/utils/mmgr/mcxt.c
@@ -750,16 +750,13 @@ MemoryContextStatsDetail(MemoryContext context, int max_children,
/*
* Return the memory used in the given context and its children.
*/
-extern Size
-MemoryContextMemUsed(MemoryContext context)
+extern void
+MemoryContextMemConsumed(MemoryContext context,
+ MemoryContextCounters *mem_consumed)
{
- MemoryContextCounters grand_totals;
-
- memset(&grand_totals, 0, sizeof(grand_totals));
-
- MemoryContextStatsInternal(context, 0, false, 100, &grand_totals, false);
+ memset(mem_consumed, 0, sizeof(*mem_consumed));
- return grand_totals.totalspace - grand_totals.freespace;
+ MemoryContextStatsInternal(context, 0, false, 100, mem_consumed, false);
}
/*
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 21e3d2f309..da2aeb647a 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -62,6 +62,12 @@ typedef struct ExplainState
ExplainWorkersState *workers_state; /* needed if parallel plan */
} ExplainState;
+typedef struct MemUsage
+{
+ Size mem_used;
+ Size mem_allocated;
+} MemUsage;
+
/* Hook for plugins to get control in ExplainOneQuery() */
typedef void (*ExplainOneQuery_hook_type) (Query *query,
int cursorOptions,
@@ -93,7 +99,7 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
ParamListInfo params, QueryEnvironment *queryEnv,
const instr_time *planduration,
const BufferUsage *bufusage,
- const Size *mem_consumed);
+ const MemUsage *mem_usage);
extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc);
extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc);
@@ -126,5 +132,8 @@ extern void ExplainOpenGroup(const char *objtype, const char *labelname,
bool labeled, ExplainState *es);
extern void ExplainCloseGroup(const char *objtype, const char *labelname,
bool labeled, ExplainState *es);
+extern void calc_mem_usage(MemUsage *mem_usage,
+ MemoryContextCounters *mem_counts_end,
+ MemoryContextCounters *mem_counts_start);
#endif /* EXPLAIN_H */
diff --git a/src/include/utils/memutils.h b/src/include/utils/memutils.h
index d7c477f229..d254a044c1 100644
--- a/src/include/utils/memutils.h
+++ b/src/include/utils/memutils.h
@@ -92,7 +92,8 @@ extern void MemoryContextStatsDetail(MemoryContext context, int max_children,
bool print_to_stderr);
extern void MemoryContextAllowInCriticalSection(MemoryContext context,
bool allow);
-extern Size MemoryContextMemUsed(MemoryContext context);
+extern void MemoryContextMemConsumed(MemoryContext context,
+ MemoryContextCounters *mem_consumed);
#ifdef MEMORY_CONTEXT_CHECKING
extern void MemoryContextCheck(MemoryContext context);
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index 123ab22f5d..863d3d79d2 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -65,7 +65,7 @@ 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
- Planning Memory: N bytes
+ Planning Memory: used=N bytes allocated=N bytes
Execution Time: N.N ms
(4 rows)
@@ -75,7 +75,7 @@ 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
- Planning Memory: N bytes
+ Planning Memory: used=N bytes allocated=N bytes
Execution Time: N.N ms
(5 rows)
@@ -84,7 +84,7 @@ select explain_filter('explain (analyze, buffers, format text) select * from int
-----------------------------------------------------------------------------------------------
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
- Planning Memory: N bytes
+ Planning Memory: used=N bytes allocated=N bytes
Execution Time: N.N ms
(4 rows)
@@ -131,7 +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> +
- <Planning-Memory>N</Planning-Memory> +
+ <Planning-Memory> +
+ <Used>N</Used> +
+ <Allocated>N</Allocated> +
+ </Planning-Memory> +
<Triggers> +
</Triggers> +
<Execution-Time>N.N</Execution-Time> +
@@ -178,7 +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 +
- Planning Memory: N +
+ Planning Memory: +
+ Used: N +
+ Allocated: N +
Triggers: +
Execution Time: N.N
(1 row)
@@ -285,7 +290,10 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
"Temp I/O Write Time": N.N +
}, +
"Planning Time": N.N, +
- "Planning Memory": N, +
+ "Planning Memory": { +
+ "Used": N, +
+ "Allocated": N +
+ }, +
"Triggers": [ +
], +
"Execution Time": N.N +
@@ -538,7 +546,10 @@ select jsonb_pretty(
], +
"Planning Time": 0.0, +
"Execution Time": 0.0, +
- "Planning Memory": 0 +
+ "Planning Memory": { +
+ "Used": 0, +
+ "Allocated": 0 +
+ } +
} +
]
(1 row)
--
2.25.1
From 60bdb0c7ccfef99cf92f9d9e3bcb7520290794ef 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/3] Report memory used for planning a query in EXPLAIN
The memory used is reported as "Planning Memory" property in EXPLAIN output
when any of options ANALYZE or SUMMARY is specified.
The memory used in the CurrentMemoryContext and its children is noted before
and after calling pg_plan_query() from ExplainOneQuery(). The difference in the
two values is reported as the memory consumed while planning the query. This
may not account for the memory allocated in memory contexts which are not
children of CurrentMemoryContext when calling pg_plan_query(). These contexts
are usually other long lived contexts, e.g. CacheMemoryContext, which are
shared by all the queries run in a session. The consumption in those can not be
attributed only to a given query and hence should not be reported any way.
Ashutosh Bapat
---
src/backend/commands/explain.c | 13 +++++++++++--
src/backend/commands/prepare.c | 7 ++++++-
src/backend/utils/mmgr/mcxt.c | 15 +++++++++++++++
src/include/commands/explain.h | 3 ++-
src/include/utils/memutils.h | 1 +
src/test/regress/expected/explain.out | 15 +++++++++++----
6 files changed, 46 insertions(+), 8 deletions(-)
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 8570b14f62..7891b70c53 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -397,9 +397,11 @@ ExplainOneQuery(Query *query, int cursorOptions,
planduration;
BufferUsage bufusage_start,
bufusage;
+ Size mem_consumed;
if (es->buffers)
bufusage_start = pgBufferUsage;
+ mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
INSTR_TIME_SET_CURRENT(planstart);
/* plan the query */
@@ -407,6 +409,8 @@ ExplainOneQuery(Query *query, int cursorOptions,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
+ mem_consumed = MemoryContextMemUsed(CurrentMemoryContext)
+ - mem_consumed;
/* calc differences of buffer counters. */
if (es->buffers)
@@ -417,7 +421,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_consumed);
}
}
@@ -527,7 +532,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 Size *mem_consumed)
{
DestReceiver *dest;
QueryDesc *queryDesc;
@@ -630,6 +635,10 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
}
+ if (es->summary && mem_consumed)
+ ExplainPropertyUInteger("Planning Memory", "bytes",
+ (uint64) *mem_consumed, 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 18f70319fc..ccae1b4477 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -583,9 +583,11 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
instr_time planduration;
BufferUsage bufusage_start,
bufusage;
+ Size mem_consumed;
if (es->buffers)
bufusage_start = pgBufferUsage;
+ mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
INSTR_TIME_SET_CURRENT(planstart);
/* Look it up in the hash table */
@@ -623,6 +625,8 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
INSTR_TIME_SET_CURRENT(planduration);
INSTR_TIME_SUBTRACT(planduration, planstart);
+ mem_consumed = MemoryContextMemUsed(CurrentMemoryContext)
+ - mem_consumed;
/* calc differences of buffer counters. */
if (es->buffers)
@@ -640,7 +644,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_consumed);
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..1ea966b186 100644
--- a/src/backend/utils/mmgr/mcxt.c
+++ b/src/backend/utils/mmgr/mcxt.c
@@ -747,6 +747,21 @@ MemoryContextStatsDetail(MemoryContext context, int max_children,
grand_totals.totalspace - grand_totals.freespace)));
}
+/*
+ * Return the memory used in the given context and its children.
+ */
+extern Size
+MemoryContextMemUsed(MemoryContext context)
+{
+ MemoryContextCounters grand_totals;
+
+ memset(&grand_totals, 0, sizeof(grand_totals));
+
+ MemoryContextStatsInternal(context, 0, false, 100, &grand_totals, false);
+
+ return grand_totals.totalspace - grand_totals.freespace;
+}
+
/*
* MemoryContextStatsInternal
* One recursion level for MemoryContextStats
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 3d3e632a0c..21e3d2f309 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 Size *mem_consumed);
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 21640d62a6..d7c477f229 100644
--- a/src/include/utils/memutils.h
+++ b/src/include/utils/memutils.h
@@ -92,6 +92,7 @@ extern void MemoryContextStatsDetail(MemoryContext context, int max_children,
bool print_to_stderr);
extern void MemoryContextAllowInCriticalSection(MemoryContext context,
bool allow);
+extern Size MemoryContextMemUsed(MemoryContext context);
#ifdef MEMORY_CONTEXT_CHECKING
extern void MemoryContextCheck(MemoryContext context);
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index 1aca77491b..123ab22f5d 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
+ Planning Memory: 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
+ Planning Memory: 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
+ Planning Memory: 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,7 @@ 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> +
+ <Planning-Memory>N</Planning-Memory> +
<Triggers> +
</Triggers> +
<Execution-Time>N.N</Execution-Time> +
@@ -174,6 +178,7 @@ select explain_filter('explain (analyze, buffers, format yaml) select * from int
Temp Read Blocks: N +
Temp Written Blocks: N +
Planning Time: N.N +
+ Planning Memory: N +
Triggers: +
Execution Time: N.N
(1 row)
@@ -280,6 +285,7 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
"Temp I/O Write Time": N.N +
}, +
"Planning Time": N.N, +
+ "Planning Memory": N, +
"Triggers": [ +
], +
"Execution Time": N.N +
@@ -531,7 +537,8 @@ select jsonb_pretty(
"Triggers": [ +
], +
"Planning Time": 0.0, +
- "Execution Time": 0.0 +
+ "Execution Time": 0.0, +
+ "Planning Memory": 0 +
} +
]
(1 row)
--
2.25.1
From 173e1df3f7a89d8c126086eacf2aa4ad87e13ac1 Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat <ashutosh.ba...@enterprisedb.com> Date: Wed, 23 Aug 2023 11:45:47 +0530 Subject: [PATCH 3/3] Separate memory context for planner's memory measurement EXPLAIN reports memory used and allocated in current memory context by the planner. The allocated memory may be influenced by the previous activity in the current memory context. Hence use a new memory context for planning the query and report statistics from that context. Ashutosh Bapat, per suggestion from David Rowley --- src/backend/commands/explain.c | 19 +++++++++++++++++-- src/backend/commands/prepare.c | 19 +++++++++++++++++-- 2 files changed, 34 insertions(+), 4 deletions(-) diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index b014d6be7f..e7df8e4455 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -402,10 +402,24 @@ ExplainOneQuery(Query *query, int cursorOptions, MemoryContextCounters mem_counts_start; MemoryContextCounters mem_counts_end; MemUsage 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(CurrentMemoryContext, &mem_counts_start); + MemoryContextMemConsumed(planner_ctx, &mem_counts_start); + saved_ctx = MemoryContextSwitchTo(planner_ctx); INSTR_TIME_SET_CURRENT(planstart); /* plan the query */ @@ -413,7 +427,8 @@ ExplainOneQuery(Query *query, int cursorOptions, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); - MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_end); + MemoryContextSwitchTo(saved_ctx); + MemoryContextMemConsumed(planner_ctx, &mem_counts_end); calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start); /* calc differences of buffer counters. */ diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c index ebc0d47ba9..eb39823d7a 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -586,10 +586,24 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, MemoryContextCounters mem_counts_start; MemoryContextCounters mem_counts_end; MemUsage 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(CurrentMemoryContext, &mem_counts_start); + MemoryContextMemConsumed(planner_ctx, &mem_counts_start); + saved_ctx = MemoryContextSwitchTo(planner_ctx); INSTR_TIME_SET_CURRENT(planstart); /* Look it up in the hash table */ @@ -627,7 +641,8 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es, INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); - MemoryContextMemConsumed(CurrentMemoryContext, &mem_counts_end); + MemoryContextSwitchTo(saved_ctx); + MemoryContextMemConsumed(planner_ctx, &mem_counts_end); calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start); /* calc differences of buffer counters. */ -- 2.25.1
