Re: Query taking too long. Problem reading explain output. - Mailing list pgsql-performance
From | Henrik |
---|---|
Subject | Re: Query taking too long. Problem reading explain output. |
Date | |
Msg-id | 8DEE0C69-B3A8-4ED5-AECB-4C7C398C8421@mac.se Whole thread Raw |
In response to | Re: Query taking too long. Problem reading explain output. (Alvaro Herrera <alvherre@commandprompt.com>) |
Responses |
Re: Query taking too long. Problem reading explain
output.
|
List | pgsql-performance |
4 okt 2007 kl. 14:30 skrev Alvaro Herrera: > Henrik wrote: > >> Ahh I had exactly 8 joins. >> Following your suggestion I raised the join_collapse_limit from 8 >> to 10 and >> the planners decision sure changed but now I have some crazy >> nested loops. >> Maybe I have some statistics wrong? > > Yeah. The problematic misestimation is exactly the innermost > indexscan, > which is wrong by two orders of magnitude: > >> -> Index Scan >> using >> tbl_file_idx on tbl_file (cost=0.01..8.66 rows=1 width=39) (actual >> time=0.057..931.546 rows=2223 loops=1) >> Index Cond: >> ((lower((file_name)::text) ~>=~ 'index.php'::character varying) AND >> (lower((file_name)::text) ~<~ 'index.phq'::character varying)) >> Filter: >> (lower((file_name)::text) ~~ 'index.php%'::text) > > This wreaks havoc on the rest of the plan. If this weren't > misestimated, it wouldn't be using those nested loops. > Correct. I changed the statistics to 500 in tbl_file.file_name and now the statistics is better. But now my big seq scan on tbl_file_Structure back and I don't know why. Pasting new explain analyze: HashAggregate (cost=467442.44..467442.47 rows=3 width=127) (actual time=25182.056..25182.169 rows=160 loops=1) -> Hash Join (cost=16106.29..467442.38 rows=3 width=127) (actual time=7825.803..25181.394 rows=160 loops=1) Hash Cond: (tbl_file.fk_filetype_id = tbl_filetype.pk_filetype_id) -> Hash Join (cost=16079.94..467413.50 rows=184 width=100) (actual time=7793.171..25148.405 rows=160 loops=1) Hash Cond: (tbl_file_structure.fk_structure_id = tbl_structure.pk_structure_id) -> Hash Join (cost=7295.70..458431.45 rows=17419 width=39) (actual time=619.779..23034.828 rows=20166 loops=1) Hash Cond: (tbl_file_structure.fk_file_id = tbl_file.pk_file_id) -> Seq Scan on tbl_file_structure (cost=0.00..357539.04 rows=18684504 width=16) (actual time=5.648..12906.913 rows=18684505 loops=1) -> Hash (cost=7269.04..7269.04 rows=2133 width=39) (actual time=613.852..613.852 rows=2223 loops=1) -> Bitmap Heap Scan on tbl_file (cost=62.50..7269.04 rows=2133 width=39) (actual time=14.672..611.803 rows=2223 loops=1) Filter: (lower((file_name)::text) ~~ 'index.php%'::text) -> Bitmap Index Scan on tbl_file_idx (cost=0.00..61.97 rows=2133 width=0) (actual time=14.205..14.205 rows=2223 loops=1) Index Cond: ((lower ((file_name)::text) ~>=~ 'index.php'::character varying) AND (lower ((file_name)::text) ~<~ 'index.phq'::character varying)) -> Hash (cost=8601.81..8601.81 rows=14595 width=77) (actual time=2076.717..2076.717 rows=24571 loops=1) -> Index Scan using tbl_structure_idx3 on tbl_structure (cost=0.00..8601.81 rows=14595 width=77) (actual time=58.620..2050.555 rows=24571 loops=1) Index Cond: (fk_archive_id = 56) -> Hash (cost=26.08..26.08 rows=22 width=59) (actual time=32.624..32.624 rows=22 loops=1) -> Nested Loop (cost=2.59..26.08 rows=22 width=59) (actual time=32.503..32.598 rows=22 loops=1) -> Nested Loop Left Join (cost=2.59..24.64 rows=1 width=41) (actual time=32.332..32.384 rows=1 loops=1) Filter: ((tbl_job_group.job_group_type = 'B'::bpchar) OR (tbl_job_group.job_group_type IS NULL)) -> Nested Loop Left Join (cost=2.59..20.20 rows=1 width=49) (actual time=27.919..27.969 rows=1 loops=1) Join Filter: (tbl_archive.fk_job_id = tbl_job.pk_job_id) -> Nested Loop (cost=2.59..13.05 rows=1 width=49) (actual time=27.897..27.904 rows=1 loops=1) Join Filter: (tbl_share.pk_share_id = tbl_archive.fk_share_id) -> Nested Loop (cost=0.00..6.43 rows=1 width=41) (actual time=19.638..19.642 rows=1 loops=1) Join Filter: (tbl_computer.pk_computer_id = tbl_share.fk_computer_id) -> Seq Scan on tbl_computer (cost=0.00..5.16 rows=1 width=20) (actual time=19.611..19.614 rows=1 loops=1) Filter: ((computer_name)::text = 'SOLARIS2'::text) -> Seq Scan on tbl_share (cost=0.00..1.12 rows=12 width=29) (actual time=0.011..0.021 rows=12 loops=1) -> Bitmap Heap Scan on tbl_archive (cost=2.59..6.60 rows=1 width=24) (actual time=8.255..8.255 rows=1 loops=1) Recheck Cond: (56 = pk_archive_id) Filter: archive_complete -> Bitmap Index Scan on tbl_archive_pkey (cost=0.00..2.59 rows=1 width=0) (actual time=8.250..8.250 rows=1 loops=1) Index Cond: (56 = pk_archive_id) -> Seq Scan on tbl_job (cost=0.00..6.51 rows=51 width=16) (actual time=0.003..0.034 rows=51 loops=1) -> Index Scan using tbl_job_group_pkey on tbl_job_group (cost=0.00..4.42 rows=1 width=13) (actual time=4.408..4.410 rows=1 loops=1) Index Cond: (tbl_job.fk_job_group_id = tbl_job_group.pk_job_group_id) -> Seq Scan on tbl_filetype (cost=0.00..1.22 rows=22 width=18) (actual time=0.169..0.178 rows=22 loops=1) Total runtime: 25182.626 ms Thanks., Henrik > -- > Alvaro Herrera http:// > www.CommandPrompt.com/ > PostgreSQL Replication, Consulting, Custom Development, 24x7 support
pgsql-performance by date: