Thread: Proposal: add a debug message about using geqo
Hi, During query tuning, users may want to check if GEQO is used or not to generate a plan. However, users can not know it by simply counting the number of tables that appear in SQL. I know we can know it by enabling GEQO_DEBUG flag, but it needs recompiling, so I think it is inconvenient. So, I would like to propose to add a debug level message that shows when PostgreSQL use GEQO. That enables users to easily see it by just changing log_min_messages. Use cases are as follows: - When investigating about the result of planning, user can determine whether the plan is chosen by the standard planning or GEQO. - When tuning PostgreSQL, user can determine the suitable value of geqo_threshold parameter. Best regards. -- KAWAMOTO Masaya <kawamoto@sraoss.co.jp> SRA OSS, Inc. Japan
Attachment
If we add that information to EXPLAIN output, the user won't need access to server logs. May be we need it in both the places. On Tue, May 10, 2022 at 6:35 AM KAWAMOTO Masaya <kawamoto@sraoss.co.jp> wrote: > > Hi, > > During query tuning, users may want to check if GEQO is used or not > to generate a plan. However, users can not know it by simply counting > the number of tables that appear in SQL. I know we can know it by > enabling GEQO_DEBUG flag, but it needs recompiling, so I think it is > inconvenient. > > So, I would like to propose to add a debug level message that shows > when PostgreSQL use GEQO. That enables users to easily see it by > just changing log_min_messages. > > Use cases are as follows: > - When investigating about the result of planning, user can determine > whether the plan is chosen by the standard planning or GEQO. > > - When tuning PostgreSQL, user can determine the suitable value of > geqo_threshold parameter. > > Best regards. > > -- > KAWAMOTO Masaya <kawamoto@sraoss.co.jp> > SRA OSS, Inc. Japan -- Best Wishes, Ashutosh Bapat
On Tue, 10 May 2022 18:49:54 +0530
Ashutosh Bapat <ashutosh.bapat.oss@gmail.com> wrote:
> If we add that information to EXPLAIN output, the user won't need
> access to server logs.
>
> May be we need it in both the places.
That sounds a nice idea. But I don't think that postgres shows in the
EXPLAIN output why the plan is selected. Would it be appropriate to
show that GEQO is used in EXPLAIN output?
As a test, I created a patch that add information about GEQO to
EXPLAIN output by the GEQO option. The output example is as follows.
What do you think about the location and content of information about GEQO?
postgres=# explain (geqo) select o.id, o.date, c.name as customer_name, bar.amount as total_amount
from orders o join customer c on o.customer_id = c.id
join (select foo.id as id, sum(foo.amount) as amount
from (select od.order_id as id, p.name as name, od.quantity as quantity, (p.price * od.quantity) as amount
from order_detail od join product p on od.product_id = p.id
) as foo
group by id) as bar on o.id = bar.id ;
QUERY PLAN
--------------------------------------------------------------------------------------------------------
Hash Join (cost=118.75..155.04 rows=200 width=48)
Hash Cond: (o.customer_id = c.id)
-> Hash Join (cost=94.58..130.34 rows=200 width=20)
Hash Cond: (o.id = bar.id)
-> Seq Scan on orders o (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=92.08..92.08 rows=200 width=12)
-> Subquery Scan on bar (cost=88.08..92.08 rows=200 width=12)
-> HashAggregate (cost=88.08..90.08 rows=200 width=12)
Group Key: od.order_id
-> Hash Join (cost=37.00..72.78 rows=2040 width=12)
Hash Cond: (od.product_id = p.id)
-> Seq Scan on order_detail od (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=22.00..22.00 rows=1200 width=8)
-> Seq Scan on product p (cost=0.00..22.00 rows=1200 width=8)
-> Hash (cost=16.30..16.30 rows=630 width=36)
-> Seq Scan on customer c (cost=0.00..16.30 rows=630 width=36)
GeqoDetails: GEQO: used, geqo_threshold: 3, Max join nodes: 3
(17 rows)
postgres=# set geqo_threshold to 16;
SET
postgres=# explain (geqo) select ... ;
QUERY PLAN
--------------------------------------------------------------------------------------------------------
Hash Join (cost=118.75..155.04 rows=200 width=48)
Hash Cond: (o.customer_id = c.id)
-> Hash Join (cost=94.58..130.34 rows=200 width=20)
Hash Cond: (o.id = bar.id)
-> Seq Scan on orders o (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=92.08..92.08 rows=200 width=12)
-> Subquery Scan on bar (cost=88.08..92.08 rows=200 width=12)
-> HashAggregate (cost=88.08..90.08 rows=200 width=12)
Group Key: od.order_id
-> Hash Join (cost=37.00..72.78 rows=2040 width=12)
Hash Cond: (od.product_id = p.id)
-> Seq Scan on order_detail od (cost=0.00..30.40 rows=2040 width=12)
-> Hash (cost=22.00..22.00 rows=1200 width=8)
-> Seq Scan on product p (cost=0.00..22.00 rows=1200 width=8)
-> Hash (cost=16.30..16.30 rows=630 width=36)
-> Seq Scan on customer c (cost=0.00..16.30 rows=630 width=36)
GeqoDetails: GEQO: not used, geqo_threshold: 16, Max join nodes: 3
(17 rows)
postgres=# explain (analyze, settings, geqo) select ...;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------
--------------------------
Hash Join (cost=118.75..155.04 rows=200 width=48) (actual time=0.104..0.113 rows=3 loops=1)
Hash Cond: (o.customer_id = c.id)
-> Hash Join (cost=94.58..130.34 rows=200 width=20) (actual time=0.042..0.048 rows=3 loops=1)
Hash Cond: (o.id = bar.id)
-> Seq Scan on orders o (cost=0.00..30.40 rows=2040 width=12) (actual time=0.003..0.005 rows=3 loops=1)
-> Hash (cost=92.08..92.08 rows=200 width=12) (actual time=0.034..0.037 rows=3 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
-> Subquery Scan on bar (cost=88.08..92.08 rows=200 width=12) (actual time=0.031..0.035 rows=3
loops=1)
-> HashAggregate (cost=88.08..90.08 rows=200 width=12) (actual time=0.030..0.033 rows=3
loops=1)
Group Key: od.order_id
Batches: 1 Memory Usage: 56kB
-> Hash Join (cost=37.00..72.78 rows=2040 width=12) (actual time=0.016..0.023 rows=7
loops=
1)
Hash Cond: (od.product_id = p.id)
-> Seq Scan on order_detail od (cost=0.00..30.40 rows=2040 width=12) (actual
time=0.0
03..0.004 rows=7 loops=1)
-> Hash (cost=22.00..22.00 rows=1200 width=8) (actual time=0.007..0.008 rows=4
loops=
1)
Buckets: 2048 Batches: 1 Memory Usage: 17kB
-> Seq Scan on product p (cost=0.00..22.00 rows=1200 width=8) (actual
time=0.00
4..0.006 rows=4 loops=1)
-> Hash (cost=16.30..16.30 rows=630 width=36) (actual time=0.019..0.020 rows=3 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
-> Seq Scan on customer c (cost=0.00..16.30 rows=630 width=36) (actual time=0.014..0.016 rows=3 loops=1)
Settings: geqo_threshold = '16'
GeqoDetails: GEQO: not used, geqo_threshold: 16, Max join nodes: 3
Planning Time: 0.516 ms
Execution Time: 0.190 ms
(24 rows)
> On Tue, May 10, 2022 at 6:35 AM KAWAMOTO Masaya <kawamoto@sraoss.co.jp> wrote:
> >
> > Hi,
> >
> > During query tuning, users may want to check if GEQO is used or not
> > to generate a plan. However, users can not know it by simply counting
> > the number of tables that appear in SQL. I know we can know it by
> > enabling GEQO_DEBUG flag, but it needs recompiling, so I think it is
> > inconvenient.
> >
> > So, I would like to propose to add a debug level message that shows
> > when PostgreSQL use GEQO. That enables users to easily see it by
> > just changing log_min_messages.
> >
> > Use cases are as follows:
> > - When investigating about the result of planning, user can determine
> > whether the plan is chosen by the standard planning or GEQO.
> >
> > - When tuning PostgreSQL, user can determine the suitable value of
> > geqo_threshold parameter.
> >
> > Best regards.
> >
> > --
> > KAWAMOTO Masaya <kawamoto@sraoss.co.jp>
> > SRA OSS, Inc. Japan
>
>
>
> --
> Best Wishes,
> Ashutosh Bapat
--
KAWAMOTO Masaya <kawamoto@sraoss.co.jp>
SRA OSS, Inc. Japan
Attachment
On Wed, Jun 1, 2022 at 11:09 PM KAWAMOTO Masaya <kawamoto@sraoss.co.jp> wrote: > That sounds a nice idea. But I don't think that postgres shows in the > EXPLAIN output why the plan is selected. Would it be appropriate to > show that GEQO is used in EXPLAIN output? I'm reminded of Greenplum's "Optimizer" line in its EXPLAIN output [1], so from that perspective I think it's intuitive. > As a test, I created a patch that add information about GEQO to > EXPLAIN output by the GEQO option. The output example is as follows. > What do you think about the location and content of information about GEQO? I am a little surprised to see GeqoDetails being printed for a plan that didn't use GEQO, but again that's probably because I'm used to GPDB's Optimizer output. And I don't have a lot of personal experience using alternative optimizers. One way to think about it might be, if we had ten alternatives, would we want a line for each showing why it wasn't selected, or just one line showing the optimizer that was selected? The latter is more compact but doesn't help you debug why something else wasn't chosen, I suppose... --Jacob [1] https://docs.vmware.com/en/VMware-Tanzu-Greenplum/6/greenplum-database/GUID-ref_guide-sql_commands-EXPLAIN.html#examples-4
On Fri, Jul 22, 2022 at 1:20 PM Jacob Champion <jchampion@timescale.com> wrote:
On Wed, Jun 1, 2022 at 11:09 PM KAWAMOTO Masaya <kawamoto@sraoss.co.jp> wrote:
> That sounds a nice idea. But I don't think that postgres shows in the
> EXPLAIN output why the plan is selected. Would it be appropriate to
> show that GEQO is used in EXPLAIN output?
I'm reminded of Greenplum's "Optimizer" line in its EXPLAIN output
[1], so from that perspective I think it's intuitive.
> As a test, I created a patch that add information about GEQO to
> EXPLAIN output by the GEQO option. The output example is as follows.
> What do you think about the location and content of information about GEQO?
I am a little surprised to see GeqoDetails being printed for a plan
that didn't use GEQO, but again that's probably because I'm used to
GPDB's Optimizer output. And I don't have a lot of personal experience
using alternative optimizers.
I agree this should be part of explain output.
I would not print the current value of geqo_threshold and leave setting display the exclusive purview of the settings option.
The presentation of only a single geqo result seems incorrect given that multiple trees can exist. In the first example below the full outer join causes 3 relations to be seen as a single relation at the top level (hence max join nodes = 4) while in the inner join case we see all 6 join nodes. There should be two outputs of GEQO in the first explain, one with join nodes of 3 and the existing one with 4.
I also don't see the point of labelling them "max"; "join nodes" seems sufficient.
While it can probably be figured out from the rest of the plan, listing the names of the join nodes may be useful (and give join nodes some company).
David J.
postgres=# explain (verbose, geqo) with gs2 (v2) as materialized ( select * from generate_series(1,1) ) select * from gs2 as gs4 full outer join (select gs2a.v2 from gs2 as gs2a, gs2 as gs2b) as gs5 using (v2), generate_series(1, 1) as gs (v1) cross join gs2 as gs3 where v1 IN (select v2 from gs2);
QUERY PLAN
----------------------------------------------------------------------------------------------------
Nested Loop (cost=0.07..0.21 rows=1 width=12)
Output: COALESCE(gs4.v2, gs2a.v2), gs.v1, gs3.v2
CTE gs2
-> Function Scan on pg_catalog.generate_series (cost=0.00..0.01 rows=1 width=4)
Output: generate_series.generate_series
Function Call: generate_series(1, 1)
-> Nested Loop (cost=0.06..0.16 rows=1 width=12)
Output: gs.v1, gs4.v2, gs2a.v2
-> Nested Loop (cost=0.02..0.06 rows=1 width=4)
Output: gs.v1
Join Filter: (gs.v1 = gs2.v2)
-> Function Scan on pg_catalog.generate_series gs (cost=0.00..0.01 rows=1 width=4)
Output: gs.v1
Function Call: generate_series(1, 1)
-> HashAggregate (cost=0.02..0.03 rows=1 width=4)
Output: gs2.v2
Group Key: gs2.v2
-> CTE Scan on gs2 (cost=0.00..0.02 rows=1 width=4)
Output: gs2.v2
-> Hash Full Join (cost=0.03..0.10 rows=1 width=8)
Output: gs4.v2, gs2a.v2
Hash Cond: (gs2a.v2 = gs4.v2)
-> Nested Loop (cost=0.00..0.05 rows=1 width=4)
Output: gs2a.v2
-> CTE Scan on gs2 gs2b (cost=0.00..0.02 rows=1 width=0)
Output: gs2b.v2
-> CTE Scan on gs2 gs2a (cost=0.00..0.02 rows=1 width=4)
Output: gs2a.v2
-> Hash (cost=0.02..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs4 (cost=0.00..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs3 (cost=0.00..0.02 rows=1 width=4)
Output: gs3.v2
GeqoDetails: GEQO: used, geqo_threshold: 2, Max join nodes: 4
(35 rows)
postgres=# explain (verbose, geqo) with gs2 (v2) as materialized ( select * from generate_series(1,1) ) select * from gs2 as gs4 join (select gs2a.v2 from gs2 as gs2a, gs2 as gs2b) as gs5 using (v2), generate_series(1, 1) as gs (v1) cross join gs2 as gs3 where v1 IN (select v2 from gs2);
QUERY PLAN
----------------------------------------------------------------------------------------------------------
Nested Loop (cost=0.02..0.18 rows=1 width=12)
Output: gs4.v2, gs.v1, gs3.v2
CTE gs2
-> Function Scan on pg_catalog.generate_series (cost=0.00..0.01 rows=1 width=4)
Output: generate_series.generate_series
Function Call: generate_series(1, 1)
-> Nested Loop (cost=0.00..0.14 rows=1 width=12)
Output: gs.v1, gs4.v2, gs3.v2
-> Nested Loop (cost=0.00..0.11 rows=1 width=8)
Output: gs.v1, gs4.v2
-> Nested Loop Semi Join (cost=0.00..0.04 rows=1 width=4)
Output: gs.v1
Join Filter: (gs.v1 = gs2.v2)
-> Function Scan on pg_catalog.generate_series gs (cost=0.00..0.01 rows=1 width=4)
Output: gs.v1
Function Call: generate_series(1, 1)
-> CTE Scan on gs2 (cost=0.00..0.02 rows=1 width=4)
Output: gs2.v2
-> Nested Loop (cost=0.00..0.05 rows=1 width=4)
Output: gs4.v2
Join Filter: (gs2a.v2 = gs4.v2)
-> CTE Scan on gs2 gs2a (cost=0.00..0.02 rows=1 width=4)
Output: gs2a.v2
-> CTE Scan on gs2 gs4 (cost=0.00..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs3 (cost=0.00..0.02 rows=1 width=4)
Output: gs3.v2
-> CTE Scan on gs2 gs2b (cost=0.00..0.02 rows=1 width=0)
Output: gs2b.v2
GeqoDetails: GEQO: used, geqo_threshold: 2, Max join nodes: 6
(30 rows)
QUERY PLAN
----------------------------------------------------------------------------------------------------
Nested Loop (cost=0.07..0.21 rows=1 width=12)
Output: COALESCE(gs4.v2, gs2a.v2), gs.v1, gs3.v2
CTE gs2
-> Function Scan on pg_catalog.generate_series (cost=0.00..0.01 rows=1 width=4)
Output: generate_series.generate_series
Function Call: generate_series(1, 1)
-> Nested Loop (cost=0.06..0.16 rows=1 width=12)
Output: gs.v1, gs4.v2, gs2a.v2
-> Nested Loop (cost=0.02..0.06 rows=1 width=4)
Output: gs.v1
Join Filter: (gs.v1 = gs2.v2)
-> Function Scan on pg_catalog.generate_series gs (cost=0.00..0.01 rows=1 width=4)
Output: gs.v1
Function Call: generate_series(1, 1)
-> HashAggregate (cost=0.02..0.03 rows=1 width=4)
Output: gs2.v2
Group Key: gs2.v2
-> CTE Scan on gs2 (cost=0.00..0.02 rows=1 width=4)
Output: gs2.v2
-> Hash Full Join (cost=0.03..0.10 rows=1 width=8)
Output: gs4.v2, gs2a.v2
Hash Cond: (gs2a.v2 = gs4.v2)
-> Nested Loop (cost=0.00..0.05 rows=1 width=4)
Output: gs2a.v2
-> CTE Scan on gs2 gs2b (cost=0.00..0.02 rows=1 width=0)
Output: gs2b.v2
-> CTE Scan on gs2 gs2a (cost=0.00..0.02 rows=1 width=4)
Output: gs2a.v2
-> Hash (cost=0.02..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs4 (cost=0.00..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs3 (cost=0.00..0.02 rows=1 width=4)
Output: gs3.v2
GeqoDetails: GEQO: used, geqo_threshold: 2, Max join nodes: 4
(35 rows)
postgres=# explain (verbose, geqo) with gs2 (v2) as materialized ( select * from generate_series(1,1) ) select * from gs2 as gs4 join (select gs2a.v2 from gs2 as gs2a, gs2 as gs2b) as gs5 using (v2), generate_series(1, 1) as gs (v1) cross join gs2 as gs3 where v1 IN (select v2 from gs2);
QUERY PLAN
----------------------------------------------------------------------------------------------------------
Nested Loop (cost=0.02..0.18 rows=1 width=12)
Output: gs4.v2, gs.v1, gs3.v2
CTE gs2
-> Function Scan on pg_catalog.generate_series (cost=0.00..0.01 rows=1 width=4)
Output: generate_series.generate_series
Function Call: generate_series(1, 1)
-> Nested Loop (cost=0.00..0.14 rows=1 width=12)
Output: gs.v1, gs4.v2, gs3.v2
-> Nested Loop (cost=0.00..0.11 rows=1 width=8)
Output: gs.v1, gs4.v2
-> Nested Loop Semi Join (cost=0.00..0.04 rows=1 width=4)
Output: gs.v1
Join Filter: (gs.v1 = gs2.v2)
-> Function Scan on pg_catalog.generate_series gs (cost=0.00..0.01 rows=1 width=4)
Output: gs.v1
Function Call: generate_series(1, 1)
-> CTE Scan on gs2 (cost=0.00..0.02 rows=1 width=4)
Output: gs2.v2
-> Nested Loop (cost=0.00..0.05 rows=1 width=4)
Output: gs4.v2
Join Filter: (gs2a.v2 = gs4.v2)
-> CTE Scan on gs2 gs2a (cost=0.00..0.02 rows=1 width=4)
Output: gs2a.v2
-> CTE Scan on gs2 gs4 (cost=0.00..0.02 rows=1 width=4)
Output: gs4.v2
-> CTE Scan on gs2 gs3 (cost=0.00..0.02 rows=1 width=4)
Output: gs3.v2
-> CTE Scan on gs2 gs2b (cost=0.00..0.02 rows=1 width=0)
Output: gs2b.v2
GeqoDetails: GEQO: used, geqo_threshold: 2, Max join nodes: 6
(30 rows)