On Mon, 2006-06-05 at 14:06, Tom Lane wrote:
> Andrew Sullivan <ajs@xxxxxxxxxxxxxxx> writes:
> > On Mon, Jun 05, 2006 at 04:07:19PM -0400, Tom Lane wrote:
> >> I'm wondering about out-of-date or nonexistent ANALYZE stats, missing
> >> custom adjustments of statistics target settings, etc.
>
> > But even the nested loop shouldn't be a "never returns" case, should
> > it? For 1800 rows?
>
> Well, it's a big query. If it ought to take a second or two, and
> instead is taking an hour or two (1800 times the expected runtime), that
> might be close enough to "never" to exhaust Chris' patience. Besides,
> we don't know whether the 1800 might itself be an underestimate (too bad
> Chris didn't provide EXPLAIN ANALYZE results). The hash plan will scale
> to larger numbers of rows much more gracefully than the nestloop ...
>
> regards, tom lane
Hello,
If anyone is curious, I've attached an explain analyze from the now
working replicated database. Explain analyze did not seem return on the
'broken' database (or at least, when we originally tried to test these,
did not return after an hour and a half, which enough time to head right
past patient into crabby...)
Chris
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=130164.68..130169.27 rows=1835 width=306) (actual time=72566.745..72569.586 rows=4525 loops=1)
Sort Key: (((uw.name_last)::text || ', '::text) || (uw.name_first)::text), o.job_title
-> Hash Join (cost=33256.35..130065.21 rows=1835 width=306) (actual time=12028.272..72488.369 rows=4525 loops=1)
Hash Cond: ("outer".keyf_locationid = "inner".keyp_locationid)
-> Hash Join (cost=33179.31..129931.78 rows=1969 width=292) (actual time=12018.508..72456.700 rows=4525 loops=1)
Hash Cond: ("outer".keyf_invoiceid = "inner".keyp_invoiceid)
-> Hash Join (cost=32709.18..128566.26 rows=2026 width=288) (actual time=11965.863..72392.930 rows=4536 loops=1)
Hash Cond: ("outer".keyf_orderid = "inner".keyp_orderid)
-> Seq Scan on timecard t (cost=0.00..94967.49 rows=43467 width=108) (actual time=25.387..60369.749 rows=49875 loops=1)
Filter: ((week_ending >= '04/02/2006'::date) AND (week_ending <= '04/30/2006'::date))
-> Hash (cost=32691.39..32691.39 rows=7114 width=184) (actual time=11922.816..11922.816 rows=7171 loops=1)
-> Hash Join (cost=28169.31..32691.39 rows=7114 width=184) (actual time=11755.198..11900.670 rows=7171 loops=1)
Hash Cond: ("outer".keyf_address_buildingid = "inner".keyp_address_buildingid)
-> Hash Join (cost=27939.87..32199.91 rows=7636 width=155) (actual time=11725.665..11857.598 rows=7197 loops=1)
Hash Cond: ("outer".keyf_supplierid = "inner".keyp_supplierid)
-> Merge Right Join (cost=27455.86..31494.40 rows=8294 width=133) (actual time=11529.683..11647.691 rows=8111 loops=1)
Merge Cond: ("outer".keyp_departmentid = "inner".keyf_parentid)
-> Index Scan using department_pkey on department d2 (cost=0.00..3702.26 rows=84966 width=22) (actual time=0.130..120.434 rows=76642 loops=1)
-> Sort (cost=27455.86..27476.60 rows=8294 width=119) (actual time=11448.943..11453.804 rows=8111 loops=1)
Sort Key: d1.keyf_parentid
-> Merge Right Join (cost=22877.04..26916.01 rows=8294 width=119) (actual time=11186.887..11410.169 rows=8111 loops=1)
Merge Cond: ("outer".keyp_departmentid = "inner".keyf_departmentid)
-> Index Scan using department_pkey on department d1 (cost=0.00..3702.26 rows=84966 width=36) (actual time=0.005..187.554 rows=84912 loops=1)
-> Sort (cost=22877.04..22897.77 rows=8294 width=91) (actual time=11140.522..11145.456 rows=8111 loops=1)
Sort Key: o.keyf_departmentid
-> Merge Right Join (cost=18887.41..22337.18 rows=8294 width=91) (actual time=10688.334..11104.926 rows=8111 loops=1)
Merge Cond: ("outer".keyf_managerid = "inner".keyf_managerid)
-> Index Scan using users_managerid on users um (cost=0.00..11590.29 rows=127619 width=23) (actual time=0.140..396.424 rows=36638 loops=1)
-> Sort (cost=18887.41..18908.14 rows=8294 width=76) (actual time=10652.067..10657.197 rows=8111 loops=1)
Sort Key: o.keyf_managerid
-> Merge Right Join (cost=12131.35..18347.56 rows=8294 width=76) (actual time=6724.630..10619.888 rows=8111 loops=1)
Merge Cond: ("outer".keyf_workerid = "inner".keyf_workerid)
-> Index Scan using users_workerid on users uw (cost=0.00..11832.81 rows=127619 width=23) (actual time=8.947..5448.600 rows=65485 loops=1)
-> Sort (cost=12131.35..12152.09 rows=8294 width=57) (actual time=5072.195..5077.354 rows=8111 loops=1)
Sort Key: o.keyf_workerid
-> Bitmap Heap Scan on orders o (cost=121.03..11591.50 rows=8294 width=57) (actual time=28.938..5030.277 rows=8111 loops=1)
Recheck Cond: (keyf_clientid = 8)
-> Bitmap Index Scan on orders_clientid_idx (cost=0.00..121.03 rows=8294 width=0) (actual time=18.476..18.476 rows=8111 loops=1)
Index Cond: (keyf_clientid = 8)
-> Hash (cost=452.21..452.21 rows=12721 width=30) (actual time=195.913..195.913 rows=12721 loops=1)
-> Seq Scan on supplier s (cost=0.00..452.21 rows=12721 width=30) (actual time=0.053..177.809 rows=12721 loops=1)
-> Hash (cost=205.75..205.75 rows=9475 width=37) (actual time=29.495..29.495 rows=9475 loops=1)
-> Seq Scan on address_building ab (cost=0.00..205.75 rows=9475 width=37) (actual time=0.052..15.243 rows=9475 loops=1)
-> Hash (cost=424.91..424.91 rows=18091 width=8) (actual time=52.592..52.592 rows=18091 loops=1)
-> Seq Scan on invoice i (cost=0.00..424.91 rows=18091 width=8) (actual time=0.047..30.662 rows=18091 loops=1)
-> Hash (cost=68.03..68.03 rows=3603 width=22) (actual time=9.669..9.669 rows=3603 loops=1)
-> Seq Scan on "location" l (cost=0.00..68.03 rows=3603 width=22) (actual time=0.013..4.870 rows=3603 loops=1)
Total runtime: 72588.500 ms
(48 rows)
