Re: Report planning memory in EXPLAIN ANALYZE

On Sun, Dec 17, 2023 at 10:31 PM Alvaro Herrera <alvherre(at)alvh(dot)no-ip(dot)org> wrote:
>
> OK, I propose the following further minor tweaks. (I modified the docs
> following the wording we have for COSTS and BUFFERS).

LGTM. Included in the attached patch.

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

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

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

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

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

postgres(at)21258=#prepare stmt as select * from pg_class where oid = $1;
PREPARE
postgres(at)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(at)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(at)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(at)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(at)21258=#prepare stmt as select * from pg_class where oid = 2345;
PREPARE
postgres(at)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(at)21258=#explain (memory) execute stmt;
QUERY PLAN
-------------------------------------------------------------------------------------
Index Scan using pg_class_oid_index on pg_class (cost=0.27..8.29
rows=1 width=273)
Index Cond: (oid = '2345'::oid)
Planner Memory: used=240 bytes allocated=8192 bytes
(3 rows)

Next time onwards it has settled on the custom plan.

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

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

--
Best Wishes,
Ashutosh Bapat