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 > 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 HerreraBreisgau, 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)
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Jan 29, 2024 at 10:43 PM Alvaro Herrera 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
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)
Re: Report planning memory in EXPLAIN ANALYZE
On Thu, Jan 18, 2024 at 5:28 PM Alvaro Herrera 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
From 1c4f33ce05fdfdbeab6e7f35d064aaa97373536b Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat
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-w09ck8z9p7eayaqq3ks9gdfhrxe...@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 [ ( option [, ...] ) ] boolean ]
TIMING [ boolean ]
SUMMARY [ boolean ]
+MEMORY [ boolean ]
FORMAT { TEXT | XML | JSON | YAML }
@@ -250,6 +251,19 @@ ROLLBACK;
+
+MEMORY
+
+
+ Include information on memory consumption by the query planning phase.
+ Specifically, include the precise amount of storage used by planner
+ in-memory structures, as well as total memory considering allocation
+ overhead.
+ The parameter defaults to FALSE.
+
+
+
+
FORMAT
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
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)
Re: Report planning memory in EXPLAIN ANALYZE
On Thu, Jan 18, 2024 at 4:42 PM Alvaro Herrera 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
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)
Re: Report planning memory in EXPLAIN ANALYZE
On Tue, Jan 16, 2024 at 8:19 PM Ashutosh Bapat
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
From 402abed4d92df981400472dac86eb3cb2f92b06f Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat
Date: Wed, 12 Jul 2023 14:34:14 +0530
Subject: [PATCH 1/2] EXPLAIN reports memory
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 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 wrote: > > At 2024-01-12 17:52:27 +0100, alvhe...@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
Re: Report planning memory in EXPLAIN ANALYZE
At 2024-01-12 17:52:27 +0100, alvhe...@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
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 HerreraBreisgau, 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)
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 wrote: > > On Sun, Dec 17, 2023 at 10:31 PM Alvaro Herrera > 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
Re: Report planning memory in EXPLAIN ANALYZE
On Sun, Dec 17, 2023 at 10:31 PM Alvaro Herrera 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.
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)
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;
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 FALSE.
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,
Re: Report planning memory in EXPLAIN ANALYZE
On Wed, Dec 13, 2023 at 1:41 AM 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 FALSE. 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 FALSE. 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 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 From 8282b3347a8535cfe09b5f2f4a0c5a6bdcba11fa Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat 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
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 FALSE. (This can still use a lot more wordsmithing of course, such as avoiding repeated use of "include/ing", ugh) -- Álvaro HerreraBreisgau, 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)
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 FALSE. 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)
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Dec 11, 2023 at 2:06 PM jian he wrote: > > On Mon, Dec 4, 2023 at 3:24 PM Ashutosh Bapat > wrote: > > > > On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov > > 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 > FALSE. > " > 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] [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
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Dec 4, 2023 at 3:24 PM Ashutosh Bapat wrote: > > On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov > 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 FALSE. " 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).
Re: Report planning memory in EXPLAIN ANALYZE
On Fri, Dec 1, 2023 at 8:27 AM Andrei Lepikhov
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
From fdd3919559cd4307536c358095fe3254bad7ab0d Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat
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 [ ( option [, ...] ) ] boolean ]
TIMING [ boolean ]
SUMMARY [ boolean ]
+MEMORY [ boolean ]
FORMAT { TEXT | XML | JSON | YAML }
@@ -250,6 +251,15 @@ ROLLBACK;
+
+MEMORY
+
+
+ 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 FALSE.
+
+
+
+
FORMAT
@@ -510,6 +520,20 @@ EXPLAIN (GENERIC_PLAN)
SELECT sum(bar) FROM test
WHERE id $1::integer AND id $2::integer
GROUP BY foo;
+
+
+
+
+ Here's an example using MEMORY option.
+
+
+EXPLAIN (MEMORY) SELECT * FROM foo;
+
+ QUERY PLAN
+-
+ Seq Scan on foo (cost=0.00..155.00 rows=1 width=4)
+ Planner Memory: used=22688 bytes allocated=32768 bytes
+(2 rows)
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
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
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 > 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)
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 wrote: > > I gave this a quick look. I think the usefulness aspect is already > established in general terms; the bit I'm not so sure about is whether > we want it enabled by default. For many cases it'd just be noise. > Perhaps we want it hidden behind something like "EXPLAIN (MEMORY)" or > such, particularly since things like "allocated" (which, per David, > seems to be the really useful metric) seems too much a PG-developer > value rather than an end-user value. It is not default but hidden behind "SUMMARY".Do you still think it requires another sub-flag MEMORY? > > If EXPLAIN (MEMORY) is added, then probably auto_explain needs a > corresponding flag, and doc updates. > > Some code looks to be in weird places. Why is calc_mem_usage, which > operates on MemoryContextCounters, in explain.c instead of mcxt.c? > why is MemUsage in explain.h instead of memnodes.h? I moved both. I > also renamed them, to MemoryContextSizeDifference() and MemoryUsage > respectively; fixup patch attached. That looks better. The functions are now available outside explain. > > I see no reason for this to be three separate patches anymore. Squashed into one along with your changes. > > The EXPLAIN docs (explain.sgml) need an update to mention the new flag > and the new output, too. Updated section describing "SUMMARY" flag. PFA updated patch. -- Best Wishes, Ashutosh Bapat From e38cde855a8aaaf77b9a01c948db7cde106993a6 Mon Sep 17 00:00:00 2001 From: Ashutosh Bapat 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; SUMMARY - 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 ANALYZE is used but otherwise is not included by default, but can be enabled using this option. Planning time in EXPLAIN EXECUTE 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); @@
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 HerreraBreisgau, Deutschland — https://www.EnterpriseDB.com/
commit 48b0c6682a9e8cf07096b979693fac09b2f7a0ba
Author: Alvaro Herrera [Álvaro Herrera
]
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;
- MemUsagemem_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, _counts_start);
@@ -429,7 +428,7 @@ ExplainOneQuery(Query *query, int cursorOptions,
INSTR_TIME_SUBTRACT(planduration, planstart);
MemoryContextSwitchTo(saved_ctx);
MemoryContextMemConsumed(planner_ctx, _counts_end);
- calc_mem_usage(_usage, _counts_end, _counts_start);
+ MemoryContextSizeDifference(_usage, _counts_start,
_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
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
From 171ce2bd03f846e7ba3e6972b1f51a432d5f75c5 Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat
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, _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, _counts_end);
+ calc_mem_usage(_usage, _counts_end, _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,
, (es->buffers ? : NULL),
- _consumed);
+ _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
Re: Report planning memory in EXPLAIN ANALYZE
Hi Ashutosh, On Fri, Sep 22, 2023 at 5:56 PM Ashutosh Bapat wrote: > Hi Andy, > Thanks for your feedback. > > On Fri, Sep 22, 2023 at 8:22 AM Andy Fan 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
Re: Report planning memory in EXPLAIN ANALYZE
Hi Andy, Thanks for your feedback. On Fri, Sep 22, 2023 at 8:22 AM Andy Fan 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
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
Re: Report planning memory in EXPLAIN ANALYZE
Using your patch I found out one redundant memory usage in the planner [1]. It
can be interesting as an example of how this patch can detect problems.
[1] Optimize planner memory consumption for huge arrays
https://www.postgresql.org/message-id/flat/em9939439a-441a-4b27-a977-ebdf5987dc49%407d14f008.com
--
Regards,
Andrei Lepikhov
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 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
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 wrote:
> Hi. I tested it.
> not sure if following is desired behavior. first run with explain,
> then run with explain(summary on).
> the second time, Planning Memory: 0 bytes.
>
> regression=# PREPARE q4 AS SELECT 1 AS a;
> explain EXECUTE q4;
> QUERY PLAN
> --
> Result (cost=0.00..0.01 rows=1 width=4)
> (1 row)
>
> regression=# explain(summary on) EXECUTE q4;
> QUERY PLAN
> --
> Result (cost=0.00..0.01 rows=1 width=4)
> Planning Time: 0.009 ms
> Planning Memory: 0 bytes
> (3 rows)
> -
Yes. This is expected since the plan is already available and no
memory is required to fetch it from the cache. I imagine, if there
were parameters to the prepared plan, it would consume some memory to
evaluate those parameters and some more memory if replanning was
required.
> previously, if you want stats of a given memory context and its
> children, you can only use MemoryContextStatsDetail.
> but it will only go to stderr or LOG_SERVER_ONLY.
> Now, MemoryContextMemUsed is being exposed. I can do something like:
>
> mem_consumed = MemoryContextMemUsed(CurrentMemoryContext);
> //do stuff.
> mem_consumed = MemoryContextMemUsed(CurrentMemoryContext) - mem_consumed;
>
> it will give me the NET memory consumed by doing staff in between. Is
> my understanding correct?
Yes.
Here are three patches based on the latest master.
0001
this is same as the previous patch with few things fixed. 1. Call
MemoryContextMemUsed() before INSTR_TIME_SET_CURRENT so that the time
taken by MemoryContextMemUsed() is not counted in planning time. 2. In
ExplainOnePlan, use a separate code block for reporting memory.
0002
This patch reports both memory allocated and memory used in the
CurrentMemoryContext at the time of planning. It converts "Planning
Memory" into a section with two values reported as "used" and
"allocated" as below
#explain (summary on) select * from pg_class c, pg_type t where
c.reltype = t.oid;
QUERY PLAN
--
Hash Join (cost=28.84..47.08 rows=414 width=533)
... snip ...
Planning Time: 9.274 ms
Planning Memory: used=80848 bytes allocated=90112 bytes
(7 rows)
In JSON format
#explain (summary on, format json) select * from pg_class c, pg_type t
where c.reltype = t.oid;
QUERY PLAN
---
[+
{ +
"Plan": {+
... snip ...
}, +
"Planning Time": 0.466, +
"Planning Memory": { +
"Used": 80608, +
"Allocated": 90112 +
}+
} +
]
(1 row)
PFA explain and explain analyze output in all the formats.
The patch adds MemoryContextMemConsumed() which is similar to
MemoryContextStats() or MemoryContextStatsDetails() except 1. the
later always prints the memory statistics to either stderr or to the
server error log and 2. it doesn't return MemoryContextCounters that
it gathered. We should probably change MemoryContextStats or
MemoryContextStatsDetails() according to those two points and not add
MemoryContextMemConsumed().
I have not merged this into 0001 yet. But once we agree upon whether
this is the right thing to do, I will merge it into 0001.
0003
When reporting memory allocated, a confusion may arise as to whether
to report the "net" memory allocated between start and end of planner
OR only the memory that remains allocated after end. This confusion
can be avoided by using an exclusive memory context (child of
CurrentMemoryContext) for planning. That's what 0003 implements as
suggested by David. As mentioned in one of the comments in the patch,
in order to measure memory allocated accurately the new MemoryContext
has to be of the same type as the memory context that will be used
otherwise by the planner i.e. CurrentMemoryContext, and should use the
same parameters. IIUC, it will always be AllocSet. So the patch uses
AllocSet and Asserts so. But in case this changes in future, we will
need a way to create a new memory context with the same properties as
the CurrentMemoryContext, a functionality missing right now. Once we
agree upon the approach, the patch will need to be merged into 0002
and in turn 0001.
--
Best Wishes,
Ashutosh Bapat
explain_planning_memory.out
Description: Binary data
From eaada36e47f914e44889e519dc377e6272b96c40 Mon Sep 17 00:00:00 2001
From:
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Aug 14, 2023 at 3:13 PM Ashutosh Bapat wrote: > > On Mon, Aug 14, 2023 at 8:22 AM Andrey Lepikhov > 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?
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Aug 14, 2023 at 8:22 AM Andrey Lepikhov 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
Re: Report planning memory in EXPLAIN ANALYZE
On Mon, Aug 14, 2023 at 5:23 AM David Rowley wrote: > > On Thu, 10 Aug 2023 at 20:33, Ashutosh Bapat > 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
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 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
Re: Report planning memory in EXPLAIN ANALYZE
On Thu, 10 Aug 2023 at 20:33, Ashutosh Bapat 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
Re: Report planning memory in EXPLAIN ANALYZE
On Fri, Aug 11, 2023 at 10:41 AM Andrey Lepikhov 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
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 wrote: On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat 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
Re: Report planning memory in EXPLAIN ANALYZE
Hi David, On Wed, Aug 9, 2023 at 8:09 PM Ashutosh Bapat 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
Re: Report planning memory in EXPLAIN ANALYZE
On Wed, Aug 9, 2023 at 8:56 PM David Rowley wrote: > > On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat > 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
Re: Report planning memory in EXPLAIN ANALYZE
On Thu, 10 Aug 2023 at 03:12, Ashutosh Bapat 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
Re: Report planning memory in EXPLAIN ANALYZE
On Wed, Aug 9, 2023 at 8:09 PM Ashutosh Bapat wrote: > > Hi David, > Replying to your comments on this thread. > > > On Tue, Aug 8, 2023 at 11:40 AM Ashutosh Bapat > > 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 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
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 > 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 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
Report planning memory in EXPLAIN ANALYZE
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.
Comments/suggestions welcome.
[1]
https://www.postgresql.org/message-id/caexhw5thqef3asvqvffcghygpfpy7o3xnvhhwbgbjfmrh8k...@mail.gmail.com
[2]
https://www.postgresql.org/message-id/CAExHW5tUcVsBkq9qT=L5vYz4e-cwQNw=KAGJrtSyzOp3F=x...@mail.gmail.com
[3]
https://www.postgresql.org/message-id/CAExHW5s=bclmmq8n_bn6iu+pjau0ds3z_6dn6ile69esmsp...@mail.gmail.com
[4]
https://www.postgresql.org/message-id/CAExHW5uVZ3E5RT9cXHaxQ_DEK7tasaMN=d6rphcao5gcxan...@mail.gmail.com
[5]
https://www.postgresql.org/message-id/CAExHW5s4EqY43oB=ne6B2=-xlgrs9zgetr1nxwkgft2j-om...@mail.gmail.com
--
Best Wishes,
Ashutosh Bapat
From 1dcadcc9cb38702f9e8882bf16173715982e36da Mon Sep 17 00:00:00 2001
From: Ashutosh Bapat
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,
- , (es->buffers ? : NULL));
+ , (es->buffers ? : NULL),
+ _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,
