Report planning memory in EXPLAIN ANALYZE

Started by Ashutosh Bapatover 2 years ago43 messages
#1Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
1 attachment(s)

Attachments:

0001-Report-memory-used-for-planning-a-query-in--20230808.patchtext/x-patch; charset=US-ASCII; name=0001-Report-memory-used-for-planning-a-query-in--20230808.patchDownload
From 1dcadcc9cb38702f9e8882bf16173715982e36da Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@enterprisedb.com>
Date: Wed, 12 Jul 2023 14:34:14 +0530
Subject: [PATCH] Report memory used for planning a query in EXPLAIN ANALYZE

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.

The memory consumption is reported as "Planning Memory" property in
EXPLAIN ANALYZE output.

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..34a1c91488 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -397,16 +397,20 @@ ExplainOneQuery(Query *query, int cursorOptions,
 					planduration;
 		BufferUsage bufusage_start,
 					bufusage;
+		Size		mem_consumed;
 
 		if (es->buffers)
 			bufusage_start = pgBufferUsage;
 		INSTR_TIME_SET_CURRENT(planstart);
+		mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
 
 		/* plan the query */
 		plan = pg_plan_query(query, queryString, cursorOptions, params);
 
 		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;
@@ -628,6 +633,10 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
 		double		plantime = INSTR_TIME_GET_DOUBLE(*planduration);
 
 		ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
+
+		if (mem_consumed)
+			ExplainPropertyUInteger("Planning Memory", "bytes",
+										(uint64) *mem_consumed, es);
 	}
 
 	/* Print info about runtime of triggers */
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index 18f70319fc..84544ce481 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -583,10 +583,12 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
 	instr_time	planduration;
 	BufferUsage bufusage_start,
 				bufusage;
+	Size		mem_consumed;
 
 	if (es->buffers)
 		bufusage_start = pgBufferUsage;
 	INSTR_TIME_SET_CURRENT(planstart);
+	mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
 
 	/* Look it up in the hash table */
 	entry = FetchPreparedStatement(execstmt->name, true);
@@ -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

#2Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Ashutosh Bapat (#1)
Re: Report planning memory in EXPLAIN ANALYZE

Hi David,
Replying to your comments on this thread.

On Tue, Aug 8, 2023 at 11:40 AM Ashutosh Bapat <ashutosh.bapat.oss@gmail.com> wrote:

Hi All,
I have been looking at memory consumed when planning a partitionwise join [1], [2] and [3]. I am using the attached patch to measure the memory consumption. The patch has been useful to detect an increased memory consumption in other patches e.g. [4] and [5]. The patch looks useful by itself. So I propose this enhancement in EXPLAIN ANALYZE.

On Wed, Aug 9, 2023 at 10:12 AM David Rowley <dgrowleyml@gmail.com> wrote:

I see you're recording the difference in the CurrentMemoryContext of
palloc'd memory before and after planning. That won't really alert us
to problems if the planner briefly allocates, say 12GBs of memory
during, say the join search then quickly pfree's it again. unless
it's an oversized chunk, aset.c won't free() any memory until
MemoryContextReset(). Chunks just go onto a freelist for reuse later.
So at the end of planning, the context may still have that 12GBs
malloc'd, yet your new EXPLAIN ANALYZE property might end up just
reporting a tiny fraction of that.

I wonder if it would be more useful to just have ExplainOneQuery()
create a new memory context and switch to that and just report the
context's mem_allocated at the end.

The memory allocated but not used is still available for use in rest
of the query processing stages. The memory context which is
CurrentMemoryContext at the time of planning is also
CurrentMemoryContext at the time of its execution if it's not
PREPAREd. So it's not exactly "consumed" by memory. But your point is
valid, that it indicates how much was allocated. Just reporting
allocated memory wont' be enough since it might have been allocated
before planning began. How about reporting both used and net allocated
memory? If we use a separate memory context as you suggest, context's
mem_allocated would be net allocated.

It's also slightly annoying that these planner-related summary outputs
are linked to EXPLAIN ANALYZE. We could be showing them in EXPLAIN
without ANALYZE. If we were to change that now, it might be a bit
annoying for the regression tests as we'd need to go and add SUMMARY
OFF in a load of places...

We do report planning time when SUMMARY ON without ANALYZE. Am I
missing something?

#select version();
version
----------------------------------------------------------------------------------------------------------
PostgreSQL 16devel on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu
9.4.0-1ubuntu1~20.04.1) 9.4.0, 64-bit
(1 row)
#explain (summary on) select * from pg_class;
QUERY PLAN
-------------------------------------------------------------
Seq Scan on pg_class (cost=0.00..18.13 rows=413 width=273)
Planning Time: 0.282 ms
(2 rows)
#explain (summary off) select * from pg_class;
QUERY PLAN
-------------------------------------------------------------
Seq Scan on pg_class (cost=0.00..18.13 rows=413 width=273)
(1 row)

I need to just make sure that the Planning Memory is reported with SUMMARY ON.

--
Best Wishes,
Ashutosh Bapat

#3Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Ashutosh Bapat (#2)
Re: Report planning memory in EXPLAIN ANALYZE

On Wed, Aug 9, 2023 at 8:09 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

Hi David,
Replying to your comments on this thread.

On Tue, Aug 8, 2023 at 11:40 AM Ashutosh Bapat <ashutosh.bapat.oss@gmail.com> wrote:

Hi All,
I have been looking at memory consumed when planning a partitionwise join [1], [2] and [3]. I am using the attached patch to measure the memory consumption. The patch has been useful to detect an increased memory consumption in other patches e.g. [4] and [5]. The patch looks useful by itself. So I propose this enhancement in EXPLAIN ANALYZE.

On Wed, Aug 9, 2023 at 10:12 AM David Rowley <dgrowleyml@gmail.com> wrote:

I see you're recording the difference in the CurrentMemoryContext of
palloc'd memory before and after planning. That won't really alert us
to problems if the planner briefly allocates, say 12GBs of memory
during, say the join search then quickly pfree's it again. unless
it's an oversized chunk, aset.c won't free() any memory until
MemoryContextReset(). Chunks just go onto a freelist for reuse later.
So at the end of planning, the context may still have that 12GBs
malloc'd, yet your new EXPLAIN ANALYZE property might end up just
reporting a tiny fraction of that.

I wonder if it would be more useful to just have ExplainOneQuery()
create a new memory context and switch to that and just report the
context's mem_allocated at the end.

The memory allocated but not used is still available for use in rest
of the query processing stages. The memory context which is
CurrentMemoryContext at the time of planning is also
CurrentMemoryContext at the time of its execution if it's not
PREPAREd. So it's not exactly "consumed" by memory. But your point is
valid, that it indicates how much was allocated. Just reporting
allocated memory wont' be enough since it might have been allocated
before planning began. How about reporting both used and net allocated
memory? If we use a separate memory context as you suggest, context's
mem_allocated would be net allocated.

Thinking more about it, I think memory used is the only right metrics.
It's an optimization in MemoryContext implementation that malloc'ed
memory is not freed when it is returned using pfree().

If we have to report allocated memory, maybe we should report as two
properties Planning Memory used, Planning Memory allocated
respectively. But again the later is an implementation detail which
may not be relevant.

--
Best Wishes,
Ashutosh Bapat

#4David Rowley
dgrowleyml@gmail.com
In reply to: Ashutosh Bapat (#3)
Re: Report planning memory in EXPLAIN ANALYZE

On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

Thinking more about it, I think memory used is the only right metrics.
It's an optimization in MemoryContext implementation that malloc'ed
memory is not freed when it is returned using free().

I guess it depends on the problem you're trying to solve. I had
thought you were trying to do some work to reduce the memory used by
the planner, so I imagined you wanted this so you could track your
progress and also to help ensure we don't make too many mistakes in
the future which makes memory consumption worse again. For that, I
imagined you'd want to know how much memory is held to ransom by the
context with malloc(), not palloc(). Is it really useful to reduce the
palloc'd memory by the end of planning if it does not reduce the
malloc'd memory?

Another way we might go about reducing planner memory is to make
changes to the allocators themselves. For example, aset rounds up to
the next power of 2. If we decided to do something like add more
freelists to double the number so we could add a mid-way point
freelist between each power of 2, then we might find it reduces the
planner memory by, say 12.5%. If we just tracked what was consumed by
palloc() that would appear to save us nothing, but it might actually
save us several malloced blocks.

David

#5Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: David Rowley (#4)
Re: Report planning memory in EXPLAIN ANALYZE

On Wed, Aug 9, 2023 at 8:56 PM David Rowley <dgrowleyml@gmail.com> wrote:

On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

Thinking more about it, I think memory used is the only right metrics.
It's an optimization in MemoryContext implementation that malloc'ed
memory is not freed when it is returned using free().

I guess it depends on the problem you're trying to solve. I had
thought you were trying to do some work to reduce the memory used by
the planner, so I imagined you wanted this so you could track your
progress and also to help ensure we don't make too many mistakes in
the future which makes memory consumption worse again.

Right.

For that, I
imagined you'd want to know how much memory is held to ransom by the
context with malloc(), not palloc(). Is it really useful to reduce the
palloc'd memory by the end of planning if it does not reduce the
malloc'd memory?

AFAIU, the memory freed by the end of planning can be used by later
stages of query processing. The memory malloc'ed during planning can
also be used at the time of execution if it was not palloc'ed or
palloc'ed but pfree'd. So I think it's useful to reduce palloc'ed
memory by the end of planning.

Another way we might go about reducing planner memory is to make
changes to the allocators themselves. For example, aset rounds up to
the next power of 2. If we decided to do something like add more
freelists to double the number so we could add a mid-way point
freelist between each power of 2, then we might find it reduces the
planner memory by, say 12.5%. If we just tracked what was consumed by
palloc() that would appear to save us nothing, but it might actually
save us several malloced blocks.

This won't just affect planner but every subsystem of PostgreSQL, not
just planner, unless we device a new context type for planner.

My point is what's relevant here is how much net memory planner asked
for. Internally how much memory PostgreSQL allocated seems relevant
for the memory context infra as such but not so much for planner
alone.

If you think that memory allocated is important, I will add both used
and (net) allocated memory to EXPLAIN output.

--
Best Wishes,
Ashutosh Bapat

#6Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Ashutosh Bapat (#2)
Re: Report planning memory in EXPLAIN ANALYZE

Hi David,

On Wed, Aug 9, 2023 at 8:09 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

I need to just make sure that the Planning Memory is reported with SUMMARY ON.

The patch reports planning memory in EXPLAIN without ANALYZE when SUMMARY = ON.

#explain (summary on) select * from a, b where a.c1 = b.c1 and a.c1 < b.c2;
QUERY PLAN
-------------------------------------------------------------------------------
Append (cost=55.90..245.70 rows=1360 width=24)
-> Hash Join (cost=55.90..119.45 rows=680 width=24)
Hash Cond: (a_1.c1 = b_1.c1)
Join Filter: (a_1.c1 < b_1.c2)
-> Seq Scan on a_p1 a_1 (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=30.40..30.40 rows=2040 width=12)
-> Seq Scan on b_p1 b_1 (cost=0.00..30.40 rows=2040 width=12)
-> Hash Join (cost=55.90..119.45 rows=680 width=24)
Hash Cond: (a_2.c1 = b_2.c1)
Join Filter: (a_2.c1 < b_2.c2)
-> Seq Scan on a_p2 a_2 (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=30.40..30.40 rows=2040 width=12)
-> Seq Scan on b_p2 b_2 (cost=0.00..30.40 rows=2040 width=12)
Planning Time: 2.220 ms
Planning Memory: 124816 bytes
(15 rows)

We are good there.

--
Best Wishes,
Ashutosh Bapat

#7Andrey Lepikhov
a.lepikhov@postgrespro.ru
In reply to: Ashutosh Bapat (#5)
Re: Report planning memory in EXPLAIN ANALYZE

On 10/8/2023 15:33, Ashutosh Bapat wrote:

On Wed, Aug 9, 2023 at 8:56 PM David Rowley <dgrowleyml@gmail.com> wrote:

On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:
I guess it depends on the problem you're trying to solve. I had
thought you were trying to do some work to reduce the memory used by
the planner, so I imagined you wanted this so you could track your
progress and also to help ensure we don't make too many mistakes in
the future which makes memory consumption worse again.
Another way we might go about reducing planner memory is to make
changes to the allocators themselves. For example, aset rounds up to
the next power of 2. If we decided to do something like add more
freelists to double the number so we could add a mid-way point
freelist between each power of 2, then we might find it reduces the
planner memory by, say 12.5%. If we just tracked what was consumed by
palloc() that would appear to save us nothing, but it might actually
save us several malloced blocks.

This won't just affect planner but every subsystem of PostgreSQL, not
just planner, unless we device a new context type for planner.

My point is what's relevant here is how much net memory planner asked
for. Internally how much memory PostgreSQL allocated seems relevant
for the memory context infra as such but not so much for planner
alone.

If you think that memory allocated is important, I will add both used
and (net) allocated memory to EXPLAIN output.

As a developer, I like having as much internal info in my EXPLAIN as
possible. But this command is designed mainly for users, not core
developers. The size of memory allocated usually doesn't make sense for
users. On the other hand, developers can watch it easily in different
ways, if needed. So, I vote for the 'memory used' metric only.

The patch looks good, passes the tests.

--
regards,
Andrey Lepikhov
Postgres Professional

#8Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Andrey Lepikhov (#7)
Re: Report planning memory in EXPLAIN ANALYZE

On Fri, Aug 11, 2023 at 10:41 AM Andrey Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

This won't just affect planner but every subsystem of PostgreSQL, not
just planner, unless we device a new context type for planner.

My point is what's relevant here is how much net memory planner asked
for. Internally how much memory PostgreSQL allocated seems relevant
for the memory context infra as such but not so much for planner
alone.

If you think that memory allocated is important, I will add both used
and (net) allocated memory to EXPLAIN output.

As a developer, I like having as much internal info in my EXPLAIN as
possible. But this command is designed mainly for users, not core
developers. The size of memory allocated usually doesn't make sense for
users. On the other hand, developers can watch it easily in different
ways, if needed. So, I vote for the 'memory used' metric only.

The patch looks good, passes the tests.

Thanks Andrey.

David, are you against reporting "memory used"? If you are not against
reporting used memory and still think that memory allocated is worth
reporting, I am fine reporting allocated memory too.

--
Best Wishes,
Ashutosh Bapat

#9David Rowley
dgrowleyml@gmail.com
In reply to: Ashutosh Bapat (#5)
Re: Report planning memory in EXPLAIN ANALYZE

On Thu, 10 Aug 2023 at 20:33, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

My point is what's relevant here is how much net memory planner asked
for.

But that's not what your patch is reporting. All you're reporting is
the difference in memory that's *currently* palloc'd from before and
after the planner ran. If we palloc'd 600 exabytes then pfree'd it
again, your metric won't change.

I'm struggling a bit to understand your goals here. If your goal is
to make a series of changes that reduces the amount of memory that's
palloc'd at the end of planning, then your patch seems to suit that
goal, but per the quote above, it seems you care about how many bytes
are palloc'd during planning and your patch does not seem track that.

With your patch as it is, to improve the metric you're reporting we
could go off and do things like pfree Paths once createplan.c is done,
but really, why would we do that? Just to make the "Planning Memory"
metric looks better doesn't seem like a worthy goal.

Instead, if we reported the context's mem_allocated, then it would
give us the flexibility to make changes to the memory context code to
have the metric look better. It might also alert us to planner
inefficiencies and problems with new code that may cause a large spike
in the amount of memory that gets allocated. Now, I'm not saying we
should add a patch that shows mem_allocated. I'm just questioning if
your proposed patch meets the goals you're trying to achieve. I just
suggested that you might want to consider something else as a metric
for your memory usage reduction work.

David

#10Andrey Lepikhov
a.lepikhov@postgrespro.ru
In reply to: David Rowley (#9)
Re: Report planning memory in EXPLAIN ANALYZE

On 14/8/2023 06:53, David Rowley wrote:

On Thu, 10 Aug 2023 at 20:33, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

My point is what's relevant here is how much net memory planner asked
for.

But that's not what your patch is reporting. All you're reporting is
the difference in memory that's *currently* palloc'd from before and
after the planner ran. If we palloc'd 600 exabytes then pfree'd it
again, your metric won't change.

I'm struggling a bit to understand your goals here. If your goal is
to make a series of changes that reduces the amount of memory that's
palloc'd at the end of planning, then your patch seems to suit that
goal, but per the quote above, it seems you care about how many bytes
are palloc'd during planning and your patch does not seem track that.

With your patch as it is, to improve the metric you're reporting we
could go off and do things like pfree Paths once createplan.c is done,
but really, why would we do that? Just to make the "Planning Memory"
metric looks better doesn't seem like a worthy goal.

Instead, if we reported the context's mem_allocated, then it would
give us the flexibility to make changes to the memory context code to
have the metric look better. It might also alert us to planner
inefficiencies and problems with new code that may cause a large spike
in the amount of memory that gets allocated. Now, I'm not saying we
should add a patch that shows mem_allocated. I'm just questioning if
your proposed patch meets the goals you're trying to achieve. I just
suggested that you might want to consider something else as a metric
for your memory usage reduction work.

Really, the current approach with the final value of consumed memory
smooths peaks of memory consumption. I recall examples likewise massive
million-sized arrays or reparameterization with many partitions where
the optimizer consumes much additional memory during planning.
Ideally, to dive into the planner issues, we should have something like
a report-in-progress in the vacuum, reporting on memory consumption at
each subquery and join level. But it looks too much for typical queries.

--
regards,
Andrey Lepikhov
Postgres Professional

#11Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: David Rowley (#9)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Aug 14, 2023 at 5:23 AM David Rowley <dgrowleyml@gmail.com> wrote:

On Thu, 10 Aug 2023 at 20:33, Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

My point is what's relevant here is how much net memory planner asked
for.

But that's not what your patch is reporting. All you're reporting is
the difference in memory that's *currently* palloc'd from before and
after the planner ran. If we palloc'd 600 exabytes then pfree'd it
again, your metric won't change.

May be I didn't use the right phrase "asked for". But I expected that
to be read in the context of "net memory" - net as an adjective.
Anyway, I will make it more clear below.

I'm struggling a bit to understand your goals here. If your goal is
to make a series of changes that reduces the amount of memory that's
palloc'd at the end of planning, then your patch seems to suit that
goal, but per the quote above, it seems you care about how many bytes
are palloc'd during planning and your patch does not seem track that.

There are three metrics here. M1: The total number of bytes that the
planner "requests". M2: The total number of bytes that "remain
palloc'ed" at a given point in time. M3: Maximum number of bytes that
were palloc'ed at any point in time during planning. Following
sequence of operations will explain the difference
p1 palloc: 100 - M1 = 100, M2 = 100, M3 = 100
p2 palloc: 100, M1 = 200, M2 = 200, M3 = 200
p3 pfree: 100, M1 = 200, M2 = 100, M3 = 200
p4 palloc: 100, M1 = 300, M2 = 200, M3 = 200
p5 palloc: 100, M1 = 400, M2 = 300, M3 = 300
p6 pfree: 100, M1 = 400, M2 = 200, M3 = 300

The patch reports M2 at the end of planning.
MemoryContextData::mem_allocated is not exactly the same as M3 but
gives indication of M3.

My goal is to reduce all three M1, M2 and M3. I don't it's easy to
track M1 and also worth the complexity. M2 and M3 instead act as rough
indicators of M1.

With your patch as it is, to improve the metric you're reporting we
could go off and do things like pfree Paths once createplan.c is done,
but really, why would we do that? Just to make the "Planning Memory"
metric looks better doesn't seem like a worthy goal.

As I mentioned earlier the CurrentMemoryContext at the time of
planning is also used during query execution. There are other contexts
like per row, per operator contexts but anything which is specific to
the running query and does not fit those contexts is allocated in this
context. If we reduce memory that remains palloc'ed (M2) at the end of
the planning, it can be used during execution. So it looks like a
worthy goal.

Instead, if we reported the context's mem_allocated, then it would
give us the flexibility to make changes to the memory context code to
have the metric look better. It might also alert us to planner
inefficiencies and problems with new code that may cause a large spike
in the amount of memory that gets allocated.

This is M3. I agree with your reasoning here. We should report M3 as
well. I will make changes to the patch.

Now, I'm not saying we
should add a patch that shows mem_allocated. I'm just questioning if
your proposed patch meets the goals you're trying to achieve. I just
suggested that you might want to consider something else as a metric
for your memory usage reduction work.

Ok. Thanks for the suggestions. More suggestions are welcome too.

[1]: https://www.merriam-webster.com/dictionary/net

--
Best Wishes,
Ashutosh Bapat

#12Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Andrey Lepikhov (#10)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Aug 14, 2023 at 8:22 AM Andrey Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

Really, the current approach with the final value of consumed memory
smooths peaks of memory consumption. I recall examples likewise massive
million-sized arrays or reparameterization with many partitions where
the optimizer consumes much additional memory during planning.
Ideally, to dive into the planner issues, we should have something like
a report-in-progress in the vacuum, reporting on memory consumption at
each subquery and join level. But it looks too much for typical queries.

Planner finishes usually finish within a second. When partitioning is
involved it might take a few dozens of seconds but it's still within a
minute and we are working to reduce that as well to a couple hundred
milliseconds at max. Tracking memory usages during this small time may
not be worth it. The tracking itself might make the planning
in-efficient and we might still miss the spikes in memory allocations,
if they are very short lived. If the planner runs for more than a few
minutes, maybe we could add some tracking.

--
Best Wishes,
Ashutosh Bapat

#13jian he
jian.universality@gmail.com
In reply to: Ashutosh Bapat (#12)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Aug 14, 2023 at 3:13 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

On Mon, Aug 14, 2023 at 8:22 AM Andrey Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

Really, the current approach with the final value of consumed memory
smooths peaks of memory consumption. I recall examples likewise massive
million-sized arrays or reparameterization with many partitions where
the optimizer consumes much additional memory during planning.
Ideally, to dive into the planner issues, we should have something like
a report-in-progress in the vacuum, reporting on memory consumption at
each subquery and join level. But it looks too much for typical queries.

Planner finishes usually finish within a second. When partitioning is
involved it might take a few dozens of seconds but it's still within a
minute and we are working to reduce that as well to a couple hundred
milliseconds at max. Tracking memory usages during this small time may
not be worth it. The tracking itself might make the planning
in-efficient and we might still miss the spikes in memory allocations,
if they are very short lived. If the planner runs for more than a few
minutes, maybe we could add some tracking.

--
Best Wishes,
Ashutosh Bapat

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)
---------------------------------------------
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?

#14Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: jian he (#13)
4 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

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.universality@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

Attachments:

explain_planning_memory.outapplication/octet-stream; name=explain_planning_memory.outDownload
0002-Report-memory-allocated-along-with-memory-u-20230824.patchtext/x-patch; charset=US-ASCII; name=0002-Report-memory-allocated-along-with-memory-u-20230824.patchDownload
From eaada36e47f914e44889e519dc377e6272b96c40 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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

0001-Report-memory-used-for-planning-a-query-in--20230824.patchtext/x-patch; charset=US-ASCII; name=0001-Report-memory-used-for-planning-a-query-in--20230824.patchDownload
From 60bdb0c7ccfef99cf92f9d9e3bcb7520290794ef Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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

0003-Separate-memory-context-for-planner-s-memor-20230824.patchtext/x-patch; charset=US-ASCII; name=0003-Separate-memory-context-for-planner-s-memor-20230824.patchDownload
From 173e1df3f7a89d8c126086eacf2aa4ad87e13ac1 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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

#15Lepikhov Andrei
a.lepikhov@postgrespro.ru
In reply to: Ashutosh Bapat (#14)
Re: Report planning memory in EXPLAIN ANALYZE

Using your patch I found out one redundant memory usage in the planner [1]Optimize planner memory consumption for huge arrays /messages/by-id/em9939439a-441a-4b27-a977-ebdf5987dc49@7d14f008.com. It can be interesting as an example of how this patch can detect problems.

[1]: Optimize planner memory consumption for huge arrays /messages/by-id/em9939439a-441a-4b27-a977-ebdf5987dc49@7d14f008.com
/messages/by-id/em9939439a-441a-4b27-a977-ebdf5987dc49@7d14f008.com

--
Regards,
Andrei Lepikhov

Show quoted text

On Thu, Aug 24, 2023, at 5:31 PM, Ashutosh Bapat wrote:

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.universality@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.

#16Andy Fan
zhihui.fan1213@gmail.com
In reply to: Lepikhov Andrei (#15)
Re: Report planning memory in EXPLAIN ANALYZE

Hi Ashutosh,

Thanks for the patch!

I think the reason why others are not excited about this is because the
benefit is not clear enough to them after the first glance and plus the
chosen wolds "Planning Memory: used " is still confusing for different
people. I admit it is clear to you absolutely, just not for others. Here
are some minor feedback from me:

1). The commit message of patch 1 just says how it does but doesn't
say why it does. After reading through the discussion, I suggest making
it clearer to others.

...
After the planning is done, it may still occupy lots of memory which is
allocated but not pfree-d. All of these memories can't be used in the later
stage. This patch will report such memory usage in order to making some
future mistakes can be found in an easier way.
...

(a description of how it works just like what you have done in the commit
message).

So if the people read the commit message, they can understand where the
function is used for.

2). at the second level, it would be cool that the user can understand the
metric without reading the commit message.

Planning Memory: used=15088 bytes allocated=16384 bytes

Word 'Planning' is kind of a time duration, so the 'used' may be the
'used' during the duration or 'used' after the duration. Obviously you
means the later one but it is not surprising others think it in the other
way. So I'd like to reword the metrics to:

Memory Occupied (Now): Parser: 1k Planner: 10k

'Now' is a cleaner signal that is a time point rather than a time
duration. 'Parser' and 'Planner' also show a timeline about the
important time point. At the same time, it cost very little coding
effort based on patch 01. Different people may have different
feelings about these words, I just hope I describe the goal clearly.

About patch 2 & patch 3, since I didn't find a good usage of it, so I
didn't put much effort on it. interesting probably is not a enough
reason for adding it IMO, since there are too many interesting things.

Personally I am pretty like patch 1, we just need to refactor some words
to make everything clearer.

--
Best Regards
Andy Fan

#17Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Andy Fan (#16)
Re: Report planning memory in EXPLAIN ANALYZE

Hi Andy,
Thanks for your feedback.

On Fri, Sep 22, 2023 at 8:22 AM Andy Fan <zhihui.fan1213@gmail.com> wrote:

1). The commit message of patch 1 just says how it does but doesn't
say why it does. After reading through the discussion, I suggest making
it clearer to others.

...
After the planning is done, it may still occupy lots of memory which is
allocated but not pfree-d. All of these memories can't be used in the later
stage. This patch will report such memory usage in order to making some
future mistakes can be found in an easier way.
...

That's a good summary of how the memory report can be used. Will
include a line about usage in the commit message.

Planning Memory: used=15088 bytes allocated=16384 bytes

Word 'Planning' is kind of a time duration, so the 'used' may be the
'used' during the duration or 'used' after the duration. Obviously you
means the later one but it is not surprising others think it in the other
way. So I'd like to reword the metrics to:

We report "PLanning Time" hence used "Planning memory". Would
"Planner" be good instead of "Planning"?

Memory Occupied (Now): Parser: 1k Planner: 10k

'Now' is a cleaner signal that is a time point rather than a time
duration. 'Parser' and 'Planner' also show a timeline about the
important time point. At the same time, it cost very little coding
effort based on patch 01. Different people may have different
feelings about these words, I just hope I describe the goal clearly.

Parsing happens before planning and that memory is not measured by
this patch. May be separately but it's out of scope of this work.
"used" and "allocated" are MemoryContext terms indicating memory
actually used vs memory allocated.

Personally I am pretty like patch 1, we just need to refactor some words
to make everything clearer.

Thanks.

--
Best Wishes,
Ashutosh Bapat

#18Andy Fan
zhihui.fan1213@gmail.com
In reply to: Ashutosh Bapat (#17)
Re: Report planning memory in EXPLAIN ANALYZE

Hi Ashutosh,

On Fri, Sep 22, 2023 at 5:56 PM Ashutosh Bapat <ashutosh.bapat.oss@gmail.com>
wrote:

Hi Andy,
Thanks for your feedback.

On Fri, Sep 22, 2023 at 8:22 AM Andy Fan <zhihui.fan1213@gmail.com> wrote:

1). The commit message of patch 1 just says how it does but doesn't
say why it does. After reading through the discussion, I suggest making
it clearer to others.

...
After the planning is done, it may still occupy lots of memory which is
allocated but not pfree-d. All of these memories can't be used in the

later

stage. This patch will report such memory usage in order to making some
future mistakes can be found in an easier way.
...

That's a good summary of how the memory report can be used. Will
include a line about usage in the commit message.

Planning Memory: used=15088 bytes allocated=16384 bytes

Word 'Planning' is kind of a time duration, so the 'used' may be the
'used' during the duration or 'used' after the duration. Obviously you
means the later one but it is not surprising others think it in the other
way. So I'd like to reword the metrics to:

We report "PLanning Time" hence used "Planning memory". Would
"Planner" be good instead of "Planning"?

I agree "Planner" is better than "Planning" personally.

Memory Occupied (Now): Parser: 1k Planner: 10k

'Now' is a cleaner signal that is a time point rather than a time
duration. 'Parser' and 'Planner' also show a timeline about the
important time point. At the same time, it cost very little coding
effort based on patch 01. Different people may have different
feelings about these words, I just hope I describe the goal clearly.

Parsing happens before planning and that memory is not measured by
this patch. May be separately but it's out of scope of this work.
"used" and "allocated" are MemoryContext terms indicating memory
actually used vs memory allocated.

Yes, I understand the terms come from MemoryContext, the complex
thing here is between time duration vs time point case. Since English
is not my native language, so I'm not too confident about insisting on
this.
So I think we can keep it as it is.

Personally I am pretty like patch 1, we just need to refactor some words
to make everything clearer.

Thanks.

David challenged something at the begining, but IIUC he also agree the
value of patch 01 as the previous statement after discussion. Since the
patch
is mild itself, so I will mark this commitfest entry as "Ready for
committer".
Please correct me if anything is wrong.

--
Best Regards
Andy Fan

#19Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Andy Fan (#18)
3 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

David challenged something at the begining, but IIUC he also agree the
value of patch 01 as the previous statement after discussion. Since the patch
is mild itself, so I will mark this commitfest entry as "Ready for committer".
Please correct me if anything is wrong.

Thanks Andy.

Here's rebased patches. A conflict in explain.out resolved.

--
Best Wishes,
Ashutosh Bapat

Attachments:

0002-Report-memory-allocated-along-with-memory-u-20231030.patchtext/x-patch; charset=US-ASCII; name=0002-Report-memory-allocated-along-with-memory-u-20231030.patchDownload
From 171ce2bd03f846e7ba3e6972b1f51a432d5f75c5 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 +++++++---
 src/tools/pgindent/typedefs.list      |  1 +
 7 files changed, 103 insertions(+), 31 deletions(-)

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index dfa4447794..efc4887244 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)
@@ -3775,6 +3782,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 381476836e..05dcb91c49 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 2179cd4b5e..e4b1aa7fdf 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)
@@ -289,7 +294,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          +
@@ -542,7 +550,10 @@ select jsonb_pretty(
          ],                                                 +
          "Planning Time": 0.0,                              +
          "Execution Time": 0.0,                             +
-         "Planning Memory": 0                               +
+         "Planning Memory": {                               +
+             "Used": 0,                                     +
+             "Allocated": 0                                 +
+         }                                                  +
      }                                                      +
  ]
 (1 row)
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 87c1aee379..bcc2f48efd 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1547,6 +1547,7 @@ MemoryContextData
 MemoryContextMethodID
 MemoryContextMethods
 MemoryStatsPrintFunc
+MemUsage
 MergeAction
 MergeActionState
 MergeAppend
-- 
2.25.1

0003-Separate-memory-context-for-planner-s-memor-20231030.patchtext/x-patch; charset=US-ASCII; name=0003-Separate-memory-context-for-planner-s-memor-20231030.patchDownload
From eb1e4ceca14572c7f2f3bf7500d83a21b872846e Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 efc4887244..9cd9b577c7 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

0001-Report-memory-used-for-planning-a-query-in--20231030.patchtext/x-patch; charset=US-ASCII; name=0001-Report-memory-used-for-planning-a-query-in--20231030.patchDownload
From a236f4dd6c518d5338b9664ffdb69203165595df Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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.

The memory consumption reported can be used to detect any large
variations in memory consumption during planning.

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 f1d71bc54e..dfa4447794 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 f9525fb572..381476836e 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 809655e16e..2179cd4b5e 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)
@@ -284,6 +289,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          +
@@ -535,7 +541,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

#20Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#19)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

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.

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.

I see no reason for this to be three separate patches anymore.

The EXPLAIN docs (explain.sgml) need an update to mention the new flag
and the new output, too.

--
Álvaro Herrera Breisgau, Deutschland — https://www.EnterpriseDB.com/

Attachments:

review.txttext/plain; charset=utf-8Download
commit 48b0c6682a9e8cf07096b979693fac09b2f7a0ba
Author:     Alvaro Herrera <alvherre@alvh.no-ip.org> [Álvaro Herrera <alvherre@alvh.no-ip.org>]
AuthorDate: Tue Nov 21 18:20:32 2023 +0100
CommitDate: Tue Nov 21 19:18:18 2023 +0100

    review

diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 9cd9b577c7..8c7f27b661 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -123,7 +123,7 @@ 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);
+								 const MemoryUsage *usage);
 static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
 									ExplainState *es);
 static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -395,14 +395,14 @@ 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;
-		MemUsage	mem_usage;
-		MemoryContext planner_ctx;
+		MemoryUsage	mem_usage;
 		MemoryContext saved_ctx;
 
 		/*
@@ -415,7 +415,6 @@ ExplainOneQuery(Query *query, int cursorOptions,
 		planner_ctx = AllocSetContextCreate(CurrentMemoryContext,
 											"explain analyze planner context",
 											ALLOCSET_DEFAULT_SIZES);
-
 		if (es->buffers)
 			bufusage_start = pgBufferUsage;
 		MemoryContextMemConsumed(planner_ctx, &mem_counts_start);
@@ -429,7 +428,7 @@ ExplainOneQuery(Query *query, int cursorOptions,
 		INSTR_TIME_SUBTRACT(planduration, planstart);
 		MemoryContextSwitchTo(saved_ctx);
 		MemoryContextMemConsumed(planner_ctx, &mem_counts_end);
-		calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start);
+		MemoryContextSizeDifference(&mem_usage, &mem_counts_start, &mem_counts_end);
 
 		/* calc differences of buffer counters. */
 		if (es->buffers)
@@ -551,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 MemUsage *mem_usage)
+			   const BufferUsage *bufusage, const MemoryUsage *mem_usage)
 {
 	DestReceiver *dest;
 	QueryDesc  *queryDesc;
@@ -656,9 +655,9 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
 
 	if (es->summary && mem_usage)
 	{
-		ExplainOpenGroup("Planning Memory", "Planning Memory", true, es);
+		ExplainOpenGroup("Planner Memory", "Planner Memory", true, es);
 		show_planning_memory(es, mem_usage);
-		ExplainCloseGroup("Planning Memory", "Planning Memory", true, es);
+		ExplainCloseGroup("Planner Memory", "Planner Memory", true, es);
 	}
 
 	/* Print info about runtime of triggers */
@@ -3801,45 +3800,22 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
  * Show planner's memory usage details.
  */
 static void
-show_planning_memory(ExplainState *es, const MemUsage *usage)
+show_planning_memory(ExplainState *es, const MemoryUsage *usage)
 {
 	if (es->format == EXPLAIN_FORMAT_TEXT)
 	{
 		appendStringInfo(es->str,
-						 "Planning Memory: used=%zu bytes allocated=%zu bytes",
-						 usage->mem_used, usage->mem_allocated);
+						 "Planner Memory: used=%zu bytes allocated=%zu bytes",
+						 usage->bytes_used, usage->bytes_allocated);
 		appendStringInfoChar(es->str, '\n');
 	}
 	else
 	{
-		ExplainPropertyInteger("Used", "bytes", usage->mem_used, es);
-		ExplainPropertyInteger("Allocated", "bytes", usage->mem_allocated, es);
+		ExplainPropertyInteger("Used", "bytes", usage->bytes_used, es);
+		ExplainPropertyInteger("Allocated", "bytes", usage->bytes_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 eb39823d7a..3d3d0ae6a3 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -585,7 +585,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
 				bufusage;
 	MemoryContextCounters mem_counts_start;
 	MemoryContextCounters mem_counts_end;
-	MemUsage	mem_usage;
+	MemoryUsage	mem_usage;
 	MemoryContext planner_ctx;
 	MemoryContext saved_ctx;
 
@@ -643,7 +643,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
 	INSTR_TIME_SUBTRACT(planduration, planstart);
 	MemoryContextSwitchTo(saved_ctx);
 	MemoryContextMemConsumed(planner_ctx, &mem_counts_end);
-	calc_mem_usage(&mem_usage, &mem_counts_end, &mem_counts_start);
+	MemoryContextSizeDifference(&mem_usage, &mem_counts_start, &mem_counts_end);
 
 	/* calc differences of buffer counters. */
 	if (es->buffers)
diff --git a/src/backend/utils/mmgr/mcxt.c b/src/backend/utils/mmgr/mcxt.c
index 94159a6799..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.
@@ -752,11 +778,11 @@ MemoryContextStatsDetail(MemoryContext context, int max_children,
  */
 extern void
 MemoryContextMemConsumed(MemoryContext context,
-						 MemoryContextCounters *mem_consumed)
+						 MemoryContextCounters *consumed)
 {
-	memset(mem_consumed, 0, sizeof(*mem_consumed));
+	memset(consumed, 0, sizeof(*consumed));
 
-	MemoryContextStatsInternal(context, 0, false, 100, mem_consumed, false);
+	MemoryContextStatsInternal(context, 0, false, 0, consumed, false);
 }
 
 /*
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 05dcb91c49..6947cbae8b 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -62,12 +62,6 @@ 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,
@@ -99,7 +93,7 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
 						   ParamListInfo params, QueryEnvironment *queryEnv,
 						   const instr_time *planduration,
 						   const BufferUsage *bufusage,
-						   const MemUsage *mem_usage);
+						   const MemoryUsage *mem_usage);
 
 extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc);
 extern void ExplainPrintTriggers(ExplainState *es, QueryDesc *queryDesc);
@@ -132,8 +126,5 @@ 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/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 50b9cc06e3..24dc0e996e 100644
--- a/src/include/utils/memutils.h
+++ b/src/include/utils/memutils.h
@@ -84,13 +84,16 @@ 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);
 extern void MemoryContextAllowInCriticalSection(MemoryContext context,
 												bool allow);
-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 e4b1aa7fdf..48e4ad1c3f 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: used=N bytes allocated=N bytes
+ Planner 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: used=N bytes allocated=N bytes
+ Planner 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: used=N bytes allocated=N bytes
+ Planner Memory: used=N bytes allocated=N bytes
  Execution Time: N.N ms
 (4 rows)
 
@@ -131,10 +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>                                 +
+     <Planner-Memory>                                  +
        <Used>N</Used>                                  +
        <Allocated>N</Allocated>                        +
-     </Planning-Memory>                                +
+     </Planner-Memory>                                 +
      <Triggers>                                        +
      </Triggers>                                       +
      <Execution-Time>N.N</Execution-Time>              +
@@ -181,7 +181,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:           +
+   Planner Memory:            +
      Used: N                  +
      Allocated: N             +
    Triggers:                  +
@@ -294,7 +294,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": {           +
+     "Planner Memory": {            +
        "Used": N,                   +
        "Allocated": N               +
      },                             +
@@ -550,7 +550,7 @@ select jsonb_pretty(
          ],                                                 +
          "Planning Time": 0.0,                              +
          "Execution Time": 0.0,                             +
-         "Planning Memory": {                               +
+         "Planner Memory": {                                +
              "Used": 0,                                     +
              "Allocated": 0                                 +
          }                                                  +
#21Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#20)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

Hi Alvaro,
Thanks for the review and the edits. Sorry for replying late.

On Tue, Nov 21, 2023 at 11:56 PM Alvaro Herrera <alvherre@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

Attachments:

0001-EXPLAIN-reports-memory-consumed-for-plannin-20231130.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20231130.patchDownload
From e38cde855a8aaaf77b9a01c948db7cde106993a6 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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

#22Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#21)
Re: Report planning memory in EXPLAIN ANALYZE

On 2023-Nov-30, Ashutosh Bapat wrote:

Hi Alvaro,
Thanks for the review and the edits. Sorry for replying late.

On Tue, Nov 21, 2023 at 11:56 PM Alvaro Herrera <alvherre@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?

Well, SUMMARY is enabled by default with ANALYZE, and I'd rather not
have planner memory consumption displayed by default with all EXPLAIN
ANALYZEs. So yeah, I still think this deserves its own option.

But let's hear others' opinions on this point. I'm only one vote here.

--
Álvaro Herrera 48°01'N 7°57'E — https://www.EnterpriseDB.com/
"All rings of power are equal,
But some rings of power are more equal than others."
(George Orwell's The Lord of the Rings)

#23Andrei Lepikhov
a.lepikhov@postgrespro.ru
In reply to: Alvaro Herrera (#22)
Re: Report planning memory in EXPLAIN ANALYZE

On 30/11/2023 18:40, Alvaro Herrera wrote:

Well, SUMMARY is enabled by default with ANALYZE, and I'd rather not
have planner memory consumption displayed by default with all EXPLAIN
ANALYZEs. So yeah, I still think this deserves its own option.

But let's hear others' opinions on this point. I'm only one vote here.

I agree; it should be disabled by default. The fact that memory
consumption outputs with byte precision (very uncomfortable for
perception) is a sign that the primary audience is developers and for
debugging purposes.

--
regards,
Andrei Lepikhov
Postgres Professional

#24Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Andrei Lepikhov (#23)
2 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

On 30/11/2023 18:40, Alvaro Herrera wrote:

Well, SUMMARY is enabled by default with ANALYZE, and I'd rather not
have planner memory consumption displayed by default with all EXPLAIN
ANALYZEs. So yeah, I still think this deserves its own option.

But let's hear others' opinions on this point. I'm only one vote here.

I agree; it should be disabled by default. The fact that memory
consumption outputs with byte precision (very uncomfortable for
perception) is a sign that the primary audience is developers and for
debugging purposes.

That's 2 vs 1. Here's patch with MEMORY option added. Replying to
Alvaro's earlier relevant comments.

If EXPLAIN (MEMORY) is added, then probably auto_explain needs a
corresponding flag, and doc updates.

auto_explain does not implement planner_hook and hence can not gather
information about planner's memory usage. So no new flag and doc
update to auto_explain. I have added a comment auto_explain.c but
probably even that's not needed. We are considering this option only
for developers and auto_explain is largely for users. So I didn't feel
like adding an implementation of planner_hook in auto_explain and use
MEMORY option. If we feel that planner's memory usage report is useful
in auto_explain, it should easy to do that in future.

The EXPLAIN docs (explain.sgml) need an update to mention the new flag
and the new output, too.

Done.

0001 is as is except explain.out and explain.sgml changes reverted.

0002 following changes. It's a separate patch for ease of review.
a. implements MEMORY option, adds tests in explain.sql and also
updates explain.sgml.
b. show_planning_memory renamed to show_planner_memory to be in sync
with the output
c. small indentation change by pgindent.

--
Best Wishes,
Ashutosh Bapat

Attachments:

0002-EXPLAIN-reports-memory-consumed-for-plannin-20231204.patchtext/x-patch; charset=US-ASCII; name=0002-EXPLAIN-reports-memory-consumed-for-plannin-20231204.patchDownload
From fdd3919559cd4307536c358095fe3254bad7ab0d Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@enterprisedb.com>
Date: Mon, 4 Dec 2023 12:12:03 +0530
Subject: [PATCH 2/2] EXPLAIN reports memory consumed for planning a query

The memory consumed is reported as "Planner Memory" property in EXPLAIN output
when any of the option MEMORY is specified.

auto_explain does not use this option since it does not planner_hook and has no
way to gather information about planner's memory usage.

Ashutosh Bapat
---
 contrib/auto_explain/auto_explain.c   |  5 ++
 doc/src/sgml/ref/explain.sgml         | 24 ++++++++++
 src/backend/commands/explain.c        | 14 +++---
 src/backend/commands/prepare.c        |  2 +-
 src/include/commands/explain.h        |  1 +
 src/test/regress/expected/explain.out | 68 +++++++++++++++++++++++++++
 src/test/regress/sql/explain.sql      |  6 +++
 7 files changed, 113 insertions(+), 7 deletions(-)

diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index c3ac27ae99..8a77e12605 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -390,6 +390,11 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
 		{
 			ExplainState *es = NewExplainState();
 
+			/*
+			 * auto_explain doesn't implement planner_hook and hence can not
+			 * gather information about planner's memory usage. Hence we leave
+			 * es->memory = false.
+			 */
 			es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze);
 			es->verbose = auto_explain_log_verbose;
 			es->buffers = (es->analyze && auto_explain_log_buffers);
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 5ba6486da1..a0a0472e4e 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,15 @@ ROLLBACK;
     </listitem>
    </varlistentry>
 
+   <varlistentry>
+    <term><literal>MEMORY</literal></term>
+    <listitem>
+     <para>
+      Include information on planner's memory consumption. Specially, include the total memory allocated by the planner and net memory that remains used at the end of the planning. It defaults to <literal>FALSE</literal>.
+     </para>
+    </listitem>
+   </varlistentry>
+
    <varlistentry>
     <term><literal>FORMAT</literal></term>
     <listitem>
@@ -510,6 +520,20 @@ EXPLAIN (GENERIC_PLAN)
   SELECT sum(bar) FROM test
     WHERE id &gt; $1::integer AND id &lt; $2::integer
     GROUP BY foo;
+</programlisting>
+  </para>
+
+  <para>
+   Here's an example using MEMORY option.
+
+<programlisting>
+EXPLAIN (MEMORY) SELECT * FROM foo;
+
+                       QUERY PLAN
+---------------------------------------------------------
+ Seq Scan on foo  (cost=0.00..155.00 rows=10000 width=4)
+ Planner Memory: used=22688 bytes allocated=32768 bytes
+(2 rows)
 </programlisting>
   </para>
  </refsect1>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 8c7f27b661..e94da4e7f8 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -122,8 +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 show_planner_memory(ExplainState *es,
+								const MemoryUsage *usage);
 static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
 									ExplainState *es);
 static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -204,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);
@@ -402,7 +404,7 @@ ExplainOneQuery(Query *query, int cursorOptions,
 					bufusage;
 		MemoryContextCounters mem_counts_start;
 		MemoryContextCounters mem_counts_end;
-		MemoryUsage	mem_usage;
+		MemoryUsage mem_usage;
 		MemoryContext saved_ctx;
 
 		/*
@@ -653,10 +655,10 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
 		ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
 	}
 
-	if (es->summary && mem_usage)
+	if (es->memory && mem_usage)
 	{
 		ExplainOpenGroup("Planner Memory", "Planner Memory", true, es);
-		show_planning_memory(es, mem_usage);
+		show_planner_memory(es, mem_usage);
 		ExplainCloseGroup("Planner Memory", "Planner Memory", true, es);
 	}
 
@@ -3800,7 +3802,7 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
  * Show planner's memory usage details.
  */
 static void
-show_planning_memory(ExplainState *es, const MemoryUsage *usage)
+show_planner_memory(ExplainState *es, const MemoryUsage *usage)
 {
 	if (es->format == EXPLAIN_FORMAT_TEXT)
 	{
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index 3d3d0ae6a3..629155fca4 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -585,7 +585,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
 				bufusage;
 	MemoryContextCounters mem_counts_start;
 	MemoryContextCounters mem_counts_end;
-	MemoryUsage	mem_usage;
+	MemoryUsage mem_usage;
 	MemoryContext planner_ctx;
 	MemoryContext saved_ctx;
 
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 6947cbae8b..f2efc7741f 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -47,6 +47,7 @@ typedef struct ExplainState
 	bool		summary;		/* print total planning and execution timing */
 	bool		settings;		/* print modified settings */
 	bool		generic;		/* generate a generic plan */
+	bool		memory;			/* print planner's memory usage information */
 	ExplainFormat format;		/* output format */
 	/* state for output formatting --- not reset for each new plan tree */
 	int			indent;			/* current indentation level */
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

0001-EXPLAIN-reports-memory-consumed-for-plannin-20231204.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20231204.patchDownload
From cd4c580926179fdc469f0e1d1c393985203dae6b Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 "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
---
 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/tools/pgindent/typedefs.list |  1 +
 7 files changed, 132 insertions(+), 4 deletions(-)

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/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

#25jian he
jian.universality@gmail.com
In reply to: Ashutosh Bapat (#24)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Dec 4, 2023 at 3:24 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

On 30/11/2023 18:40, Alvaro Herrera wrote:

Well, SUMMARY is enabled by default with ANALYZE, and I'd rather not
have planner memory consumption displayed by default with all EXPLAIN
ANALYZEs. So yeah, I still think this deserves its own option.

But let's hear others' opinions on this point. I'm only one vote here.

I agree; it should be disabled by default. The fact that memory
consumption outputs with byte precision (very uncomfortable for
perception) is a sign that the primary audience is developers and for
debugging purposes.

That's 2 vs 1. Here's patch with MEMORY option added. Replying to
Alvaro's earlier relevant comments.

"Include information on planner's memory consumption. Specially,
include the total memory allocated by the planner and net memory that
remains used at the end of the planning. It defaults to
<literal>FALSE</literal>.
"
doc/src/sgml/ref/explain.sgml
I can view MemoryContextSizeDifference, figure out the meaning.

But I am not sure "net memory that remains used at the end of the
planning" is the correct description.
(I am not native english speaker).

#26Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: jian he (#25)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Dec 11, 2023 at 2:06 PM jian he <jian.universality@gmail.com> wrote:

On Mon, Dec 4, 2023 at 3:24 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov
<a.lepikhov@postgrespro.ru> wrote:

On 30/11/2023 18:40, Alvaro Herrera wrote:

Well, SUMMARY is enabled by default with ANALYZE, and I'd rather not
have planner memory consumption displayed by default with all EXPLAIN
ANALYZEs. So yeah, I still think this deserves its own option.

But let's hear others' opinions on this point. I'm only one vote here.

I agree; it should be disabled by default. The fact that memory
consumption outputs with byte precision (very uncomfortable for
perception) is a sign that the primary audience is developers and for
debugging purposes.

That's 2 vs 1. Here's patch with MEMORY option added. Replying to
Alvaro's earlier relevant comments.

"Include information on planner's memory consumption. Specially,
include the total memory allocated by the planner and net memory that
remains used at the end of the planning. It defaults to
<literal>FALSE</literal>.
"
doc/src/sgml/ref/explain.sgml
I can view MemoryContextSizeDifference, figure out the meaning.

But I am not sure "net memory that remains used at the end of the
planning" is the correct description.
(I am not native english speaker).

The word "net" is used as an adjective, see [1]https://www.merriam-webster.com/dictionary/net (as an adjective)

[1]: https://www.merriam-webster.com/dictionary/net (as an adjective)

Does that help? Do you have any other wording proposal?

--
Best Wishes,
Ashutosh Bapat

#27Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#26)
Re: Report planning memory in EXPLAIN ANALYZE

I would replace the text in explain.sgml with this:

+      Include information on memory consumption by the query planning phase.
+      This includes the precise amount of storage used by planner in-memory
+      structures, as well as overall total consumption of planner memory,
+      including allocation overhead.
+      This parameter defaults to </literal>FALSE</literal>.

and remove the new example you're adding; it's not really necessary.

In struct ExplainState, I'd put the new member just below summary.

If we're creating a new memory context for planner, we don't need the
"mem_counts_start" thing, and we don't need the
MemoryContextSizeDifference thing. Just add the
MemoryContextMemConsumed() function (which ISTM should be just below
MemoryContextMemAllocated() instead of in the middle of the
MemoryContextStats implementation), and
just report the values we get there. I think the SizeDifference stuff
increases surface damage for no good reason.

ExplainOnePlan() is given a MemoryUsage object (or, if we do as above
and no longer have a MemoryUsage struct at all in the first place, a
MemoryContextCounters object) even when the MEMORY option is false.
This means we waste computing memory usage when not needed. Let's avoid
that useless overhead.

I'd also do away with the comment you added in explain_ExecutorEnd() and
do just this, below setting of es->summary:

+           /* No support for MEMORY option */
+           /* es->memory = false; */

We don't need to elaborate more at present.

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
"Doing what he did amounts to sticking his fingers under the hood of the
implementation; if he gets his fingers burnt, it's his problem." (Tom Lane)

#28Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Alvaro Herrera (#27)
Re: Report planning memory in EXPLAIN ANALYZE

On 2023-Dec-12, Alvaro Herrera wrote:

I would replace the text in explain.sgml with this:

+      Include information on memory consumption by the query planning phase.
+      This includes the precise amount of storage used by planner in-memory
+      structures, as well as overall total consumption of planner memory,
+      including allocation overhead.
+      This parameter defaults to </literal>FALSE</literal>.

(This can still use a lot more wordsmithing of course, such as avoiding
repeated use of "include/ing", ugh)

--
Álvaro Herrera Breisgau, Deutschland — https://www.EnterpriseDB.com/
"The Gord often wonders why people threaten never to come back after they've
been told never to return" (www.actsofgord.com)

#29Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#27)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

On Wed, Dec 13, 2023 at 1:41 AM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

I would replace the text in explain.sgml with this:

+      Include information on memory consumption by the query planning phase.
+      This includes the precise amount of storage used by planner in-memory
+      structures, as well as overall total consumption of planner memory,
+      including allocation overhead.
+      This parameter defaults to </literal>FALSE</literal>.

To me consumption in the "... total consumption ..." part is same as
allocation and that includes allocation overhead as well as any memory
that was allocated but remained unused (see discussion [1] if you
haven't already) ultimately. Mentioning "total consumption" and
"allocation overhead" seems more confusing.

How about
+      Include information on memory consumption by the query planning phase.
+      Report the precise amount of storage used by planner in-memory
+      structures, and total memory considering allocation overhead.
+      The parameter defaults to <literal>FALSE</literal>.

Takes care of your complaint about multiple include/ing as well.

and remove the new example you're adding; it's not really necessary.

Done.

In struct ExplainState, I'd put the new member just below summary.

Done

If we're creating a new memory context for planner, we don't need the
"mem_counts_start" thing, and we don't need the
MemoryContextSizeDifference thing. Just add the
MemoryContextMemConsumed() function (which ISTM should be just below
MemoryContextMemAllocated() instead of in the middle of the
MemoryContextStats implementation), and
just report the values we get there. I think the SizeDifference stuff
increases surface damage for no good reason.

240 bytes are used right after creating a memory context i.e.
mem_counts_start.totalspace = 8192 and mem_counts_start.freespace =
7952. To account for that I used two counters and calculated the
difference. If no planning is involved in EXECUTE <prepared statement>
it will show 240 bytes used instead of 0. Barring that for all
practical purposes 240 bytes negligible. E.g. 240 bytes is 4% of the
amount of memory used for planning a simple query " select 'x' ". But
your suggestion simplifies the code a lot. An error of 240 bytes seems
worth the code simplification. So did that way.

ExplainOnePlan() is given a MemoryUsage object (or, if we do as above
and no longer have a MemoryUsage struct at all in the first place, a
MemoryContextCounters object) even when the MEMORY option is false.
This means we waste computing memory usage when not needed. Let's avoid
that useless overhead.

Done.

Also avoided creating a memory context and switching to it when
es->memory = false.

I'd also do away with the comment you added in explain_ExecutorEnd() and
do just this, below setting of es->summary:

+           /* No support for MEMORY option */
+           /* es->memory = false; */

Done.

I ended up rewriting most of the code, so squashed everything into a
single patch as attached.

--
Best Wishes,
Ashutosh Bapat

Attachments:

0001-EXPLAIN-reports-memory-consumed-for-plannin-20231213.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20231213.patchDownload
From 8282b3347a8535cfe09b5f2f4a0c5a6bdcba11fa Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 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".

Ashutosh Bapat, reviewed by David Rowley and Alvaro Herrera
---
 contrib/auto_explain/auto_explain.c   |  2 +
 doc/src/sgml/ref/explain.sgml         | 13 +++++
 src/backend/commands/explain.c        | 67 +++++++++++++++++++++++++-
 src/backend/commands/prepare.c        | 26 +++++++++-
 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, 197 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..49c61cce69 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,18 @@ ROLLBACK;
     </listitem>
    </varlistentry>
 
+   <varlistentry>
+    <term><literal>MEMORY</literal></term>
+    <listitem>
+     <para>
+      Include information on memory consumption by the query planning phase.
+      Report the precise amount of storage used by planner in-memory
+      structures, and 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..0a18a7abd8 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 (mem_counts)
+	{
+		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=%zu bytes allocated=%zu bytes",
+						 mem_counts->totalspace - mem_counts->freespace,
+						 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..7e947e023b 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -583,6 +583,23 @@ 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)
+	{
+		/*
+		 * 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;
@@ -624,6 +641,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 +663,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 9fc83f11f6..58634e5ad6 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

#30Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#29)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

OK, I propose the following further minor tweaks. (I modified the docs
following the wording we have for COSTS and BUFFERS).

There are two things that still trouble me a bit. First, we assume that
the planner is using an AllocSet context, which I guess is true, but if
somebody runs the planner in a context of a different memcxt type, it's
going to be a problem. So far we don't have infrastructure for creating
a context of the same type as another context. Maybe it's too fine a
point to worry about, for sure.

The other question is about trying to support the EXPLAIN EXECUTE case.
Do you find that case really useful? In a majority of cases planning is
not going to happen because it was already done by PREPARE (where we
_don't_ report memory, because we don't have EXPLAIN there), so it seems
a bit weird. I suppose you could make it useful if you instructed the
user to set plan_cache_mode to custom, assuming that does actually work
(I didn't try).

--
Álvaro Herrera 48°01'N 7°57'E — https://www.EnterpriseDB.com/
"El hombre nunca sabe de lo que es capaz hasta que lo intenta" (C. Dickens)

Attachments:

fixups.txttext/plain; charset=utf-8Download
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 49c61cce69..26809d68d5 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -256,8 +256,9 @@ ROLLBACK;
     <listitem>
      <para>
       Include information on memory consumption by the query planning phase.
-      Report the precise amount of storage used by planner in-memory
-      structures, and total memory considering allocation overhead.
+      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>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 0a18a7abd8..2fa93998a3 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -660,7 +660,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
 		ExplainPropertyFloat("Planning Time", "ms", 1000.0 * plantime, 3, es);
 	}
 
-	if (mem_counts)
+	if (es->memory && mem_counts != NULL)
 	{
 		ExplainOpenGroup("Planner Memory", "Planner Memory", true, es);
 		show_planner_memory(es, mem_counts);
@@ -3813,9 +3813,9 @@ show_planner_memory(ExplainState *es,
 	if (es->format == EXPLAIN_FORMAT_TEXT)
 	{
 		appendStringInfo(es->str,
-						 "Planner Memory: used=%zu bytes allocated=%zu bytes",
-						 mem_counts->totalspace - mem_counts->freespace,
-						 mem_counts->totalspace);
+						 "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
diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c
index 7e947e023b..e1577c791a 100644
--- a/src/backend/commands/prepare.c
+++ b/src/backend/commands/prepare.c
@@ -590,9 +590,12 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
 	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.
+		 * 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,
#31Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#30)
Re: Report planning memory in EXPLAIN ANALYZE

On Sun, Dec 17, 2023 at 10:31 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

OK, I propose the following further minor tweaks. (I modified the docs
following the wording we have for COSTS and BUFFERS).

LGTM. Included in the attached patch.

There are two things that still trouble me a bit. First, we assume that
the planner is using an AllocSet context, which I guess is true, but if
somebody runs the planner in a context of a different memcxt type, it's
going to be a problem. So far we don't have infrastructure for creating
a context of the same type as another context. Maybe it's too fine a
point to worry about, for sure.

I had considered this point. Different contexts take different
arguments for creation, so some jugglery is required to create a
context based on type. It looked more than necessary for the limited
scope of this patch. That's why I settled on the assertion. If we see
the need in future we can always add that support.

The other question is about trying to support the EXPLAIN EXECUTE case.
Do you find that case really useful? In a majority of cases planning is
not going to happen because it was already done by PREPARE (where we
_don't_ report memory, because we don't have EXPLAIN there), so it seems
a bit weird. I suppose you could make it useful if you instructed the
user to set plan_cache_mode to custom, assuming that does actually work
(I didn't try).

If we set plan_cache_mode to force_custom_plan, we always plan the
statement and thus report memory.

You are right that we don't always plan the statement when EXECUTE Is
issued. But it seems we create plan underneath EXECUTE more often that
I expected. And the report looks mildly useful and interesting.

postgres@21258=#prepare stmt as select * from pg_class where oid = $1;
PREPARE
postgres@21258=#explain (memory) execute stmt(1); -- first time
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '1'::oid)
Planner Memory: used=40448 bytes allocated=81920 bytes
(3 rows)

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '1'::oid)
Planner Memory: used=40368 bytes allocated=81920 bytes
(3 rows)

observe that the memory used is slightly different from the first
time. So when the plan is created again something happens that eats
few bytes less. I didn't investigate what.

The same output repeats if the statement is executed 3 more times.
That's as many times a custom plan is created for a statement by
default.

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = $1)
Planner Memory: used=40272 bytes allocated=81920 bytes
(3 rows)

Observe that the memory used is less here again. So when creating the
generic plan something happened which causes the change in memory
consumption. Didn't investigate.

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = $1)
Planner Memory: used=3520 bytes allocated=24576 bytes
(3 rows)

And now the planner is settled on very low value but still non-zero or
240 bytes. I think the parameter evaluation takes that much memory.
Haven't verified.

If we use an non-parameterized statement
postgres@21258=#prepare stmt as select * from pg_class where oid = 2345;
PREPARE
postgres@21258=#explain (memory) execute stmt;
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '2345'::oid)
Planner Memory: used=37200 bytes allocated=65536 bytes
(3 rows)

first time memory is consumed by the planner.

postgres@21258=#explain (memory) execute stmt;
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '2345'::oid)
Planner Memory: used=240 bytes allocated=8192 bytes
(3 rows)

Next time onwards it has settled on the custom plan.

I think there's something to learn and investigate from memory numbers
here. So not completely meaningless and useless.

I added that support on lines of "planning time".

--
Best Wishes,
Ashutosh Bapat

#32Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Ashutosh Bapat (#31)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

Forgot to attach patch. Here it is

On Mon, Dec 18, 2023 at 12:55 PM Ashutosh Bapat
<ashutosh.bapat.oss@gmail.com> wrote:

On Sun, Dec 17, 2023 at 10:31 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

OK, I propose the following further minor tweaks. (I modified the docs
following the wording we have for COSTS and BUFFERS).

LGTM. Included in the attached patch.

There are two things that still trouble me a bit. First, we assume that
the planner is using an AllocSet context, which I guess is true, but if
somebody runs the planner in a context of a different memcxt type, it's
going to be a problem. So far we don't have infrastructure for creating
a context of the same type as another context. Maybe it's too fine a
point to worry about, for sure.

I had considered this point. Different contexts take different
arguments for creation, so some jugglery is required to create a
context based on type. It looked more than necessary for the limited
scope of this patch. That's why I settled on the assertion. If we see
the need in future we can always add that support.

The other question is about trying to support the EXPLAIN EXECUTE case.
Do you find that case really useful? In a majority of cases planning is
not going to happen because it was already done by PREPARE (where we
_don't_ report memory, because we don't have EXPLAIN there), so it seems
a bit weird. I suppose you could make it useful if you instructed the
user to set plan_cache_mode to custom, assuming that does actually work
(I didn't try).

If we set plan_cache_mode to force_custom_plan, we always plan the
statement and thus report memory.

You are right that we don't always plan the statement when EXECUTE Is
issued. But it seems we create plan underneath EXECUTE more often that
I expected. And the report looks mildly useful and interesting.

postgres@21258=#prepare stmt as select * from pg_class where oid = $1;
PREPARE
postgres@21258=#explain (memory) execute stmt(1); -- first time
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '1'::oid)
Planner Memory: used=40448 bytes allocated=81920 bytes
(3 rows)

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '1'::oid)
Planner Memory: used=40368 bytes allocated=81920 bytes
(3 rows)

observe that the memory used is slightly different from the first
time. So when the plan is created again something happens that eats
few bytes less. I didn't investigate what.

The same output repeats if the statement is executed 3 more times.
That's as many times a custom plan is created for a statement by
default.

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = $1)
Planner Memory: used=40272 bytes allocated=81920 bytes
(3 rows)

Observe that the memory used is less here again. So when creating the
generic plan something happened which causes the change in memory
consumption. Didn't investigate.

postgres@21258=#explain (memory) execute stmt(1);
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = $1)
Planner Memory: used=3520 bytes allocated=24576 bytes
(3 rows)

And now the planner is settled on very low value but still non-zero or
240 bytes. I think the parameter evaluation takes that much memory.
Haven't verified.

If we use an non-parameterized statement
postgres@21258=#prepare stmt as select * from pg_class where oid = 2345;
PREPARE
postgres@21258=#explain (memory) execute stmt;
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '2345'::oid)
Planner Memory: used=37200 bytes allocated=65536 bytes
(3 rows)

first time memory is consumed by the planner.

postgres@21258=#explain (memory) execute stmt;
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '2345'::oid)
Planner Memory: used=240 bytes allocated=8192 bytes
(3 rows)

Next time onwards it has settled on the custom plan.

I think there's something to learn and investigate from memory numbers
here. So not completely meaningless and useless.

I added that support on lines of "planning time".

--
Best Wishes,
Ashutosh Bapat

--
Best Wishes,
Ashutosh Bapat

Attachments:

0001-EXPLAIN-reports-memory-consumed-for-plannin-20231218.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20231218.patchDownload
From 3b7dfb5ae99cd3e3ec35618007811a78341a77d4 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 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".

Ashutosh Bapat, reviewed by David Rowley and Alvaro Herrera
---
 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 9fc83f11f6..58634e5ad6 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

#33Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#32)
Re: Report planning memory in EXPLAIN ANALYZE

I think this patch is mostly OK and decided to use it to test something
else. In doing so I noticed one small thing that bothers me: if
planning uses buffers, and those were requested to be reported, we get
something like this at the end of the explain

Planning:
Buffers: shared hit=120 read=30
Planning Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

This looks a bit unpleasant. Wouldn't it be much nicer if the Planning
thingies were all reported together in the Planning group?

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Time: 0.892 ms

This is easier said than done. First, moving "Time" to be in the same
group would break tools that are already parsing the current format. So
maybe we should leave that one alone. So that means we end up with
this:

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

Better than the original, I think, even if not perfect. Looking at the
code, this is a bit of a mess to implement, because of the way
show_buffer_usage is coded; currently it has an internal
increment/decrement of indentation, so in order to report memory we
would have to move the indentation change to outside show_buffer_usage
(I think it does belong outside, but the determination of whether to
print or not is quite messy, so we'd need a new function returning
boolean).

Alternatively we could move the memory reportage to within
show_buffer_usage, but that seems worse.

Or we could leave it as you have it, but to me that's akin to giving up
on doing it nicely.

--
Álvaro Herrera Breisgau, Deutschland — https://www.EnterpriseDB.com/
"I think my standards have lowered enough that now I think 'good design'
is when the page doesn't irritate the living f*ck out of me." (JWZ)

#34Abhijit Menon-Sen
ams@toroid.org
In reply to: Alvaro Herrera (#33)
Re: Report planning memory in EXPLAIN ANALYZE

At 2024-01-12 17:52:27 +0100, alvherre@alvh.no-ip.org wrote:

I think this patch is mostly OK

(After the last few rounds of changes, it looks fine to me too.)

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

[…]

Or we could leave it as you have it, but to me that's akin to giving up
on doing it nicely.

For completeness, there's a third option, which is easier to write and a
bit more friendly to the sort of thing that might already be parsing
"Planning Time", viz.,

Planning Buffers: shared hit=120 read=30
Planning Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

(Those "bytes" look slightly odd to me in the midst of all the x=y
pieces, but that's probably not worth thinking about.)

-- Abhijit

#35Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#33)
Re: Report planning memory in EXPLAIN ANALYZE

Replying to both Alvaro and Abhijit in this email.

On Fri, Jan 12, 2024 at 10:22 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

I think this patch is mostly OK and decided to use it to test something
else. In doing so I noticed one small thing that bothers me: if
planning uses buffers, and those were requested to be reported, we get
something like this at the end of the explain

Planning:
Buffers: shared hit=120 read=30
Planning Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

This looks a bit unpleasant. Wouldn't it be much nicer if the Planning
thingies were all reported together in the Planning group?

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Time: 0.892 ms

This is easier said than done. First, moving "Time" to be in the same
group would break tools that are already parsing the current format. So
maybe we should leave that one alone. So that means we end up with
this:

We have not been careful when reporting buffer usage. Both Buffers and
I/O timings are related to buffers. Ideally we should have created a
separate section for buffers and reported the usage and timings stats
under it. If done that way, actually the output looks better.

Planning Buffers:
usage: shared hit = ...
i/o timings: shared read =...
Planning Memory:
Planning Time:

Further we may move the Buffers, Memory and Timing under "Planning"
section. So it looks like
Planning
Buffers
Usage
I/O Timings
Memory
Time

We could bite the bullet and fix it in the next major release when
such compatibility breakage is expected if not welcome. If we go this
route, it will be good to commit this patch and then work on
refactoring.

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

Better than the original, I think, even if not perfect. Looking at the
code, this is a bit of a mess to implement, because of the way
show_buffer_usage is coded; currently it has an internal
increment/decrement of indentation, so in order to report memory we
would have to move the indentation change to outside show_buffer_usage
(I think it does belong outside, but the determination of whether to
print or not is quite messy, so we'd need a new function returning
boolean).

If we could change show_buffer_usage() to print something like below
when no buffers are used or no time is spent in I/O, we won't need the
boolean and all the complexity in showing "Planning" and indenting.
Planning:
Buffers: no buffers used
I/O timings: none
Memory: used ...

That would be a backward compatibility break, but impact would be
minor. Still that will bring I/O Timings at the same level as Memory
which is wrong.

Using a boolean return and moving es->indent-- outside of
show_buffer_usage would be less elegant.

Alternatively we could move the memory reportage to within
show_buffer_usage, but that seems worse.

Agreed.

On Fri, Jan 12, 2024 at 10:53 PM Abhijit Menon-Sen <ams@toroid.org> wrote:

At 2024-01-12 17:52:27 +0100, alvherre@alvh.no-ip.org wrote:

I think this patch is mostly OK

(After the last few rounds of changes, it looks fine to me too.)

Planning:
Buffers: shared hit=120 read=30
Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

[…]

Or we could leave it as you have it, but to me that's akin to giving up
on doing it nicely.

For completeness, there's a third option, which is easier to write and a
bit more friendly to the sort of thing that might already be parsing
"Planning Time", viz.,

Planning Buffers: shared hit=120 read=30
Planning Memory: used=67944 bytes allocated=73728 bytes
Planning Time: 0.892 ms

And
Planning I/O Timings: shared ... .

To me it looks similar to Alvaro's first option.

(Those "bytes" look slightly odd to me in the midst of all the x=y
pieces, but that's probably not worth thinking about.)

How about separating those with ",". That would add a minor
inconsistency with how values in Buffers and I/O Timings sections are
reported.

--
Best Wishes,
Ashutosh Bapat

#36Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Ashutosh Bapat (#35)
2 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

On Tue, Jan 16, 2024 at 8:19 PM Ashutosh Bapat
<ashutosh.bapat.oss@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

Attachments:

0001-EXPLAIN-reports-memory-consumed-for-plannin-20240118.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20240118.patchDownload
From 402abed4d92df981400472dac86eb3cb2f92b06f Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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-w09ck8z9p7eaYAqq3Ks9GDfhrxeWBw@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

0002-Use-Planning-section-to-report-memory-per-A-20240118.patchtext/x-patch; charset=US-ASCII; name=0002-Use-Planning-section-to-report-memory-per-A-20240118.patchDownload
From 4637dd99b19bf8e3670a12850589aad235350a5a Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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

#37Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#36)
Re: Report planning memory in EXPLAIN ANALYZE

On 2024-Jan-18, Ashutosh Bapat wrote:

Hmm ... TBH I don't like the "showed_planning" thing very much, but if
we need to conditionalize the printing of "Planning:" on whether we
print either of buffers or memory, maybe there's no way around something
like what you propose.

However, I don't understand this output change, and I think it indicates
a bug in the logic there:

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)

Does this really make sense?

--
Álvaro Herrera PostgreSQL Developer — https://www.EnterpriseDB.com/
"Linux transformó mi computadora, de una `máquina para hacer cosas',
en un aparato realmente entretenido, sobre el cual cada día aprendo
algo nuevo" (Jaime Salinas)

#38Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#37)
Re: Report planning memory in EXPLAIN ANALYZE

On Thu, Jan 18, 2024 at 4:42 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

On 2024-Jan-18, Ashutosh Bapat wrote:

Hmm ... TBH I don't like the "showed_planning" thing very much, but if
we need to conditionalize the printing of "Planning:" on whether we
print either of buffers or memory, maybe there's no way around something
like what you propose.

right.

However, I don't understand this output change, and I think it indicates
a bug in the logic there:

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)

Does this really make sense?

The EXPLAIN output produces something like below
explain_filter
---------------------------------------------------------
Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N)
Planning:
Memory: used=N bytes, allocated=N bytes
(3 rows)

but function explain_filter(), defined in explain.sql, removes line
containing Planning: and we end up with output
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)

Hence this weird difference.

--
Best Wishes,
Ashutosh Bapat

#39Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#38)
Re: Report planning memory in EXPLAIN ANALYZE

On 2024-Jan-18, Ashutosh Bapat wrote:

The EXPLAIN output produces something like below
explain_filter
---------------------------------------------------------
Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N)
Planning:
Memory: used=N bytes, allocated=N bytes
(3 rows)

but function explain_filter(), defined in explain.sql, removes line
containing Planning: and we end up with output
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)

Hence this weird difference.

Ah, okay, that makes sense. (I actually think this is a bit insane, and
I would hope that we can revert commit eabba4a3eb71 eventually, but I
don't think that needs to hold up your proposed patch.)

--
Álvaro Herrera 48°01'N 7°57'E — https://www.EnterpriseDB.com/
"At least to kernel hackers, who really are human, despite occasional
rumors to the contrary" (LWN.net)

#40Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#39)
1 attachment(s)
Re: Report planning memory in EXPLAIN ANALYZE

On Thu, Jan 18, 2024 at 5:28 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

On 2024-Jan-18, Ashutosh Bapat wrote:

The EXPLAIN output produces something like below
explain_filter
---------------------------------------------------------
Seq Scan on int8_tbl i8 (cost=N.N..N.N rows=N width=N)
Planning:
Memory: used=N bytes, allocated=N bytes
(3 rows)

but function explain_filter(), defined in explain.sql, removes line
containing Planning: and we end up with output
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)

Hence this weird difference.

Ah, okay, that makes sense. (I actually think this is a bit insane, and
I would hope that we can revert commit eabba4a3eb71 eventually, but I
don't think that needs to hold up your proposed patch.)

Thanks. Attached is rebased and squashed patch.

--
Best Wishes,
Ashutosh Bapat

Attachments:

0001-EXPLAIN-reports-memory-consumed-for-plannin-20240123.patchtext/x-patch; charset=US-ASCII; name=0001-EXPLAIN-reports-memory-consumed-for-plannin-20240123.patchDownload
From 1c4f33ce05fdfdbeab6e7f35d064aaa97373536b Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat <ashutosh.bapat@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 "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-w09ck8z9p7eaYAqq3Ks9GDfhrxeWBw@mail.gmail.com
---
 contrib/auto_explain/auto_explain.c   |   2 +
 doc/src/sgml/ref/explain.sgml         |  14 +++
 src/backend/commands/explain.c        | 124 ++++++++++++++++++++++----
 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, 245 insertions(+), 17 deletions(-)

diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index c7aacd7812..dcb5d6c9e5 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 843472e6dd..e912f7dae0 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -119,9 +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 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);
@@ -202,6 +205,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 +402,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 +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_counts);
+		}
+
 		/* 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_counts : 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_counts)
 {
 	DestReceiver *dest;
 	QueryDesc  *queryDesc;
@@ -615,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);
 	}
 
@@ -3546,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 ||
@@ -3568,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);
@@ -3678,9 +3728,6 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 			}
 			appendStringInfoChar(es->str, '\n');
 		}
-
-		if (show_planning)
-			es->indent--;
 	}
 	else
 	{
@@ -3726,6 +3773,8 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 								 3, es);
 		}
 	}
+
+	return show_planning;
 }
 
 /*
@@ -3766,6 +3815,51 @@ 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 bool
+show_planner_memory(ExplainState *es,
+					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,
+						 "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
+	{
+		show_planning = false;
+
+		ExplainPropertyInteger("Memory Used", "bytes",
+							   mem_counts->totalspace - mem_counts->freespace,
+							   es);
+		ExplainPropertyInteger("Memory Allocated", "bytes",
+							   mem_counts->totalspace, es);
+	}
+
+	return show_planning;
+}
+
+
 /*
  * 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..ab62a22bb6 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 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..c03006250f 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 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..55694505a7 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)
+   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)
+
 -- 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

#41Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#40)
Re: Report planning memory in EXPLAIN ANALYZE

Okay, so I gave this another look and concluded that I definitely didn't
like the whole business of having one level open the explain group and
return outwards whether it had been done so that the other level would
close it. So I made the code do what I said I thought it should do
(adding a new function peek_buffer_usage to report whether BUFFERS would
print anything), and I have to say that it looks much better to me with
that.

I also added a trivial test for EXPLAIN EXECUTE, which was uncovered,
and some other minor stylistic changes.

And with that I pushed it.

--
Álvaro Herrera 48°01'N 7°57'E — https://www.EnterpriseDB.com/
#error "Operator lives in the wrong universe"
("Use of cookies in real-time system development", M. Gleixner, M. Mc Guire)

#42Ashutosh Bapat
ashutosh.bapat.oss@gmail.com
In reply to: Alvaro Herrera (#41)
Re: Report planning memory in EXPLAIN ANALYZE

On Mon, Jan 29, 2024 at 10:43 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

Okay, so I gave this another look and concluded that I definitely didn't
like the whole business of having one level open the explain group and
return outwards whether it had been done so that the other level would
close it. So I made the code do what I said I thought it should do
(adding a new function peek_buffer_usage to report whether BUFFERS would
print anything), and I have to say that it looks much better to me with
that.

Hmm. ExplainOnePlan certainly looks better with this.

I also added a trivial test for EXPLAIN EXECUTE, which was uncovered,
and some other minor stylistic changes.

Thanks. Looks fine to me.

And with that I pushed it.

Thanks a lot.

--
Best Wishes,
Ashutosh Bapat

#43Alvaro Herrera
alvherre@alvh.no-ip.org
In reply to: Ashutosh Bapat (#42)
Re: Report planning memory in EXPLAIN ANALYZE

On 2024-Jan-30, Ashutosh Bapat wrote:

On Mon, Jan 29, 2024 at 10:43 PM Alvaro Herrera <alvherre@alvh.no-ip.org> wrote:

I also added a trivial test for EXPLAIN EXECUTE, which was uncovered,
and some other minor stylistic changes.

Thanks. Looks fine to me.

Thanks for looking!

--
Álvaro Herrera Breisgau, Deutschland — https://www.EnterpriseDB.com/
¡Ay, ay, ay! Con lo mucho que yo lo quería (bis)
se fue de mi vera ... se fue para siempre, pa toíta ... pa toíta la vida
¡Ay Camarón! ¡Ay Camarón! (Paco de Lucía)