0002-Report-memory-allocated-along-with-memory-u-20230824.patch

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