Re: postgres FROM clause problem

Alle 18:53, giovedì 11 marzo 2004, hai scritto:
> Paolo Tavalazzi <ptavalazzi(at)charta(dot)it> writes:
> > [ query plans after updating to 7.4.2 ]
>
> Okay, they're certainly a lot closer than before, so I think I was right
> that you were getting bitten somehow by the pg_statistic alignment
> problem. It seems like there may still be a bug lurking though. The
> rows-out estimates are 7 versus 9 for the middle nested-loop join.
> That might just be roundoff error, or there may be something else going
> on. Also the estimates for the top join are 7 versus 1 rows, which
> seems too large a ratio to be explainable as roundoff error.
>
> Could I pester you to send me a pg_dump dump of this database off-list?
> I'd like to trace through the planner with a debugger and see exactly
> where the results are diverging.
>
> regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: if posting/reading through Usenet, please send an appropriate
> subscribe-nomail command to majordomo(at)postgresql(dot)org so that your
> message can get through to the mailing list cleanly

I have reconstructed the database from zero and i have tried the usual two query
in various conditions :

#################### NO ANALYZE : similar execution time but different plan

1)

FROM
seat,spettacoli,tran,teatri
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=51.00..51.00 rows=1 width=37) (actual time=4163.191..4164.883 rows=1317 loops=1)
-> Nested Loop (cost=0.00..50.99 rows=1 width=37) (actual time=0.253..3868.225 rows=67218 loops=1)
-> Nested Loop (cost=0.00..46.15 rows=1 width=50) (actual time=0.215..2903.309 rows=68167 loops=1)
-> Nested Loop (cost=0.00..41.31 rows=1 width=38) (actual time=0.124..508.361 rows=68174 loops=1)
-> Index Scan using time_idx on tran (cost=0.00..17.11 rows=5 width=32) (actual time=0.068..42.747 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..4.83 rows=1 width=14) (actual time=0.007..0.010 rows=3 loops=24923)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..4.83 rows=1 width=31) (actual time=0.031..0.032 rows=1 loops=68174)
Index Cond: ((spettacoli.system = "outer".system) AND ("outer".thea_code = spettacoli.teatro) AND (("outer".perf_code)::text = (spettacoli.code)::text))
-> Index Scan using teatri_pkey on teatri (cost=0.00..4.82 rows=1 width=13) (actual time=0.011..0.012 rows=1 loops=68167)
Index Cond: (teatri.code = "outer".thea_code)
Total runtime: 4165.522 ms

2) FROM
seat,teatri,tran,spettacoli
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=51.00..51.00 rows=1 width=37) (actual time=4161.159..4162.811 rows=1317 loops=1)
-> Nested Loop (cost=0.00..50.99 rows=1 width=37) (actual time=0.251..3865.205 rows=67218 loops=1)
-> Nested Loop (cost=0.00..46.14 rows=1 width=51) (actual time=0.186..1512.814 rows=67225 loops=1)
-> Nested Loop (cost=0.00..41.31 rows=1 width=38) (actual time=0.121..507.694 rows=68174 loops=1)
-> Index Scan using time_idx on tran (cost=0.00..17.11 rows=5 width=32) (actual time=0.066..40.742 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..4.83 rows=1 width=14) (actual time=0.008..0.011 rows=3 loops=24923)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
-> Index Scan using teatri_pkey on teatri (cost=0.00..4.82 rows=1 width=13) (actual time=0.011..0.012 rows=1 loops=68174)
Index Cond: (teatri.code = "outer".thea_code)
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..4.83 rows=1 width=31) (actual time=0.031..0.032 rows=1 loops=67225)
Index Cond: ((spettacoli.system = "outer".system) AND (spettacoli.teatro = "outer".code) AND (("outer".perf_code)::text = (spettacoli.code)::text))
Total runtime: 4163.446 ms

###### AFTER ANALYZE TARGET STATISTICS 100 : same time execution and same query plan

1) FROM
seat,spettacoli,tran,teatri

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=53216.67..53216.67 rows=1 width=32) (actual time=2697.680..2699.333 rows=1317 loops=1)
-> Nested Loop (cost=47299.78..53216.66 rows=1 width=32) (actual time=653.173..2412.029 rows=67218 loops=1)
-> Nested Loop (cost=47299.78..53183.92 rows=9 width=45) (actual time=653.132..1489.709 rows=68167 loops=1)
-> Merge Join (cost=47299.78..53103.62 rows=16 width=45) (actual time=653.081..1105.783 rows=24919 loops=1)
Merge Cond: (("outer".system = "inner".system) AND ("outer".teatro = "inner".thea_code) AND (("outer".code)::text = "inner"."?column5?"))
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..5257.29 rows=56079 width=26) (actual time=0.038..61.964 rows=55565 loops=1)
-> Sort (cost=47299.78..47331.23 rows=12580 width=30) (actual time=652.556..658.198 rows=24923 loops=1)
Sort Key: tran.system, tran.thea_code, (tran.perf_code)::text
-> Index Scan using time_idx on tran (cost=0.00..46443.15 rows=12580 width=30) (actual time=0.081..73.187 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..5.00 rows=1 width=14) (actual time=0.006..0.009 rows=3 loops=24919)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
-> Index Scan using teatri_pkey on teatri (cost=0.00..3.63 rows=1 width=13) (actual time=0.010..0.011 rows=1 loops=68167)
Index Cond: (teatri.code = "outer".thea_code)
Total runtime: 2703.439 ms

2) FROM
seat,teatri,tran,spettacoli

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=53209.45..53209.49 rows=7 width=32) (actual time=2699.970..2701.667 rows=1317 loops=1)
-> Nested Loop (cost=47299.78..53209.38 rows=7 width=32) (actual time=659.834..2414.241 rows=67218 loops=1)
-> Nested Loop (cost=47299.78..53183.92 rows=7 width=45) (actual time=659.792..1494.365 rows=68167 loops=1)
-> Merge Join (cost=47299.78..53103.62 rows=16 width=45) (actual time=659.738..1102.368 rows=24919 loops=1)
Merge Cond: (("outer".system = "inner".system) AND ("outer".teatro = "inner".thea_code) AND (("outer".code)::text = "inner"."?column5?"))
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..5257.29 rows=56079 width=26) (actual time=0.039..62.206 rows=55565 loops=1)
-> Sort (cost=47299.78..47331.23 rows=12580 width=30) (actual time=659.212..664.639 rows=24923 loops=1)
Sort Key: tran.system, tran.thea_code, (tran.perf_code)::text
-> Index Scan using time_idx on tran (cost=0.00..46443.15 rows=12580 width=30) (actual time=0.082..73.680 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..5.00 rows=1 width=14) (actual time=0.006..0.009 rows=3 loops=24919)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
-> Index Scan using teatri_pkey on teatri (cost=0.00..3.63 rows=1 width=13) (actual time=0.010..0.011 rows=1 loops=68167)
Index Cond: (teatri.code = "outer".thea_code)
Total runtime: 2705.860 ms

### AFTER VACCUM ANALYZE : different execution time and query plan

1) FROM
seat,spettacoli,tran,teatri
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=53935.10..53935.13 rows=7 width=32) (actual time=2072.545..2074.096 rows=1317 loops=1)
-> Hash Join (cost=53908.03..53935.03 rows=7 width=32) (actual time=1538.514..1789.602 rows=67218 loops=1)
Hash Cond: ("outer".code = "inner".teatro)
-> Seq Scan on teatri (cost=0.00..22.62 rows=862 width=13) (actual time=0.008..0.500 rows=862 loops=1)
-> Hash (cost=53908.01..53908.01 rows=7 width=45) (actual time=1538.391..1538.391 rows=0 loops=1)
-> Nested Loop (cost=47422.83..53908.01 rows=7 width=45) (actual time=652.643..1486.794 rows=68167 loops=1)
-> Merge Join (cost=47422.83..53811.72 rows=16 width=45) (actual time=652.582..1093.848 rows=24919 loops=1)
Merge Cond: (("outer".system = "inner".system) AND ("outer".teatro = "inner".thea_code) AND (("outer".code)::text = "inner"."?column5?"))
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..5842.37 rows=56079 width=26) (actual time=0.034..63.328 rows=55565 loops=1)
-> Sort (cost=47422.83..47454.27 rows=12576 width=30) (actual time=652.055..656.872 rows=24923 loops=1)
Sort Key: tran.system, tran.thea_code, (tran.perf_code)::text
-> Index Scan using time_idx on tran (cost=0.00..46566.51 rows=12576 width=30) (actual time=0.089..74.088 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..6.00 rows=1 width=14) (actual time=0.006..0.009 rows=3 loops=24919)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
Total runtime: 2079.186 ms

2) FROM
seat,teatri,tran,spettacoli
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
HashAggregate (cost=53949.76..53949.77 rows=1 width=32) (actual time=2705.489..2707.201 rows=1317 loops=1)
-> Nested Loop (cost=47422.83..53949.75 rows=1 width=32) (actual time=659.431..2419.617 rows=67218 loops=1)
-> Nested Loop (cost=47422.83..53908.01 rows=9 width=45) (actual time=659.386..1499.370 rows=68167 loops=1)
-> Merge Join (cost=47422.83..53811.72 rows=16 width=45) (actual time=659.325..1105.997 rows=24919 loops=1)
Merge Cond: (("outer".system = "inner".system) AND ("outer".teatro = "inner".thea_code) AND (("outer".code)::text = "inner"."?column5?"))
-> Index Scan using spe_sys_tea_perf on spettacoli (cost=0.00..5842.37 rows=56079 width=26) (actual time=0.034..63.630 rows=55565 loops=1)
-> Sort (cost=47422.83..47454.27 rows=12576 width=30) (actual time=658.794..664.366 rows=24923 loops=1)
Sort Key: tran.system, tran.thea_code, (tran.perf_code)::text
-> Index Scan using time_idx on tran (cost=0.00..46566.51 rows=12576 width=30) (actual time=0.089..74.386 rows=24923 loops=1)
Index Cond: (("time" >= ('2004-03-01 00:00:00'::timestamp without time zone)::timestamp with time zone) AND ("time" <= ('2004-03-08 23:59:59'::timestamp without time zone)::timestamp with time zone))
-> Index Scan using id_system_idx on seat (cost=0.00..6.00 rows=1 width=14) (actual time=0.007..0.009 rows=3 loops=24919)
Index Cond: (("outer".id = seat.bt_id) AND ("outer".system = seat.system))
-> Index Scan using teatri_pkey on teatri (cost=0.00..4.63 rows=1 width=13) (actual time=0.010..0.011 rows=1 loops=68167)
Index Cond: (teatri.code = "outer".thea_code)
Total runtime: 2711.333 ms

For me it would not be a problem to send the dump to you but the db is 2,5G size
and the pg_dump -Fc -Z 9 -R -O is 81M.
I have not tried if diminishing the dimension of the db the problem persist.
How we can make?
What do you use for debug planner ???