Re: weird hash plan cost, starting with pg10

On Mon, Mar 23, 2020 at 01:50:59PM -0300, Alvaro Herrera wrote:
> While messing with EXPLAIN on a query emitted by pg_dump, I noticed that
> current Postgres 10 emits weird bucket/batch/memory values for certain
> hash nodes:
>
> -> Hash (cost=0.11..0.11 rows=10 width=12) (actual time=0.002..0.002 rows=1 loops=8)
> Buckets: 2139062143 Batches: 2139062143 Memory Usage: 8971876904722400kB
> -> Function Scan on unnest init_1 (cost=0.01..0.11 rows=10 width=12) (actual time=0.001..0.001 rows=1 loops=8)
>
> It shows normal values in 9.6.

Your message wasn't totally clear, but this is a live bug on 13dev.

It's actually broken on 9.6, but the issue isn't exposed until commit
6f236e1eb: "psql: Add tab completion for logical replication",
..which adds a nondefault ACL.

I reproduced the problem with this recipe, which doesn't depend on
c.relispartion or pg_get_partkeydef, and everything else shifting underfoot..

|CREATE TABLE t (i int); REVOKE ALL ON t FROM pryzbyj; explain analyze SELECT (SELECT 1 FROM (SELECT * FROM unnest(c.relacl)AS acl WHERE NOT EXISTS ( SELECT 1 FROM unnest(c.relacl) AS init(init_acl) WHERE acl=init_acl)) as foo) AS relacl , EXISTS (SELECT 1 FROM pg_depend WHERE objid=c.oid) FROM pg_class c ORDER BY c.oid;
| Index Scan using pg_class_oid_index on pg_class c (cost=0.27..4704.25 rows=333 width=9) (actual time=16.257..28.054 rows=334 loops=1)
| SubPlan 1
| -> Hash Anti Join (cost=2.25..3.63 rows=1 width=4) (actual time=0.024..0.024 rows=0 loops=334)
| Hash Cond: (acl.acl = init.init_acl)
| -> Function Scan on unnest acl (cost=0.00..1.00 rows=100 width=12) (actual time=0.007..0.007 rows=1 loops=334)
| -> Hash (cost=1.00..1.00 rows=100 width=12) (actual time=0.015..0.015 rows=2 loops=179)
| Buckets: 2139062143 Batches: 2139062143 Memory Usage: 8971876904722400kB
| -> Function Scan on unnest init (cost=0.00..1.00 rows=100 width=12) (actual time=0.009..0.010 rows=2 loops=179)
| SubPlan 2
| -> Seq Scan on pg_depend (cost=0.00..144.21 rows=14 width=0) (never executed)
| Filter: (objid = c.oid)
| SubPlan 3
| -> Seq Scan on pg_depend pg_depend_1 (cost=0.00..126.17 rows=7217 width=4) (actual time=0.035..6.270 rows=7220 loops=1)

When I finally gave up on thinking I knew what branch was broken, I got:

|3fc6e2d7f5b652b417fa6937c34de2438d60fa9f is the first bad commit
|commit 3fc6e2d7f5b652b417fa6937c34de2438d60fa9f
|Author: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
|Date: Mon Mar 7 15:58:22 2016 -0500
|
| Make the upper part of the planner work by generating and comparing Paths.

--
Justin