Date: Tue, 24 Mar 2020 01:23:26 -0500
From: Justin Pryzby <pryzby@telsasoft.com>
To: Alvaro Herrera <alvherre@2ndquadrant.com>
Cc: pgsql-hackers@lists.postgresql.org, Tom Lane <tgl@sss.pgh.pa.us>,
	Thomas Munro <thomas.munro@gmail.com>
Subject: Re: weird hash plan cost, starting with pg10
Message-ID: <20200324062325.GD21443@telsasoft.com>
References: <20200323165059.GA24950@alvherre.pgsql>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20200323165059.GA24950@alvherre.pgsql>
User-Agent: Mutt/1.9.4 (2018-02-28)
Precedence: bulk

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@sss.pgh.pa.us>
|Date:   Mon Mar 7 15:58:22 2016 -0500
|
|    Make the upper part of the planner work by generating and comparing Paths.

-- 
Justin