Re: Query taking too long. Problem reading explain output. - Mailing list pgsql-performance

3 okt 2007 kl. 16:15 skrev Tom Lane:

> Henrik <henke@mac.se> writes:
>> Here is the query if needed.
>> explain analyze SELECT file_name FROM tbl_file_structure JOIN
>> tbl_file ON pk_file_id = fk_file_id JOIN tbl_structure ON
>> pk_structure_id = fk_structure_id JOIN tbl_archive ON pk_archive_id
>> =fk_archive_id JOIN tbl_share ON pk_share_id =fk_share_id JOIN
>> tbl_computer ON pk_computer_id = fk_computer_id JOIN tbl_filetype ON
>> pk_filetype_id = fk_filetype_id LEFT OUTER JOIN tbl_job ON
>> tbl_archive.fk_job_id = pk_job_id LEFT OUTER JOIN tbl_job_group ON
>> tbl_job.fk_job_group_id = pk_job_group_id WHERE LOWER(file_name) LIKE
>> LOWER('index.php%') AND (computer_name = 'SOLARIS2') AND
>> (fk_archive_id = 56) AND archive_complete = true  AND (job_group_type
>> = 'B' OR job_group_type IS NULL) GROUP BY file_name, file_ctime,
>> structure_path, pk_computer_id, filetype_icon, computer_name,
>> share_name, share_path;
>
> [ counts the JOINs... ]  Try raising join_collapse_limit.  I think the
> planner may be neglecting to consider the join order you need.
>
>             regards, tom lane

Hi,

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?

Same query this is the new explain analyze:

  HashAggregate  (cost=48.40..48.41 rows=1 width=127) (actual
time=22898.513..22898.613 rows=160 loops=1)
    ->  Nested Loop Left Join  (cost=2.60..48.38 rows=1 width=127)
(actual time=10.984..22897.964 rows=160 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.60..43.94 rows=1
width=135) (actual time=10.976..22896.856 rows=160 loops=1)
                Join Filter: (tbl_archive.fk_job_id = tbl_job.pk_job_id)
                ->  Nested Loop  (cost=2.60..36.79 rows=1 width=135)
(actual time=10.955..22887.675 rows=160 loops=1)
                      Join Filter: (tbl_share.pk_share_id =
tbl_archive.fk_share_id)
                      ->  Nested Loop  (cost=0.01..30.18 rows=1
width=143) (actual time=10.941..22885.841 rows=160 loops=1)
                            Join Filter: (tbl_computer.pk_computer_id
= tbl_share.fk_computer_id)
                            ->  Nested Loop  (cost=0.01..28.91 rows=1
width=122) (actual time=10.925..22883.458 rows=160 loops=1)
                                  ->  Nested Loop  (cost=0.01..26.73
rows=1 width=102) (actual time=10.915..22881.411 rows=160 loops=1)
                                        ->  Nested Loop
(cost=0.01..20.45 rows=1 width=41) (actual time=0.107..10693.572
rows=20166 loops=1)
                                              ->  Nested Loop
(cost=0.01..10.15 rows=1 width=41) (actual time=0.080..986.100
rows=2223 loops=1)
                                                    Join Filter:
(tbl_filetype.pk_filetype_id = tbl_file.fk_filetype_id)
                                                    ->  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)
                                                    ->  Seq Scan on
tbl_filetype  (cost=0.00..1.22 rows=22 width=18) (actual
time=0.002..0.011 rows=22 loops=2223)
                                              ->  Index Scan using
tbl_file_structure_idx on tbl_file_structure  (cost=0.00..10.29
rows=1 width=16) (actual time=0.722..4.356 rows=9 loops=2223)
                                                    Index Cond:
(tbl_file.pk_file_id = tbl_file_structure.fk_file_id)
                                        ->  Index Scan using
tbl_structure_pkey on tbl_structure  (cost=0.00..6.27 rows=1
width=77) (actual time=0.603..0.603 rows=0 loops=20166)
                                              Index Cond:
(tbl_structure.pk_structure_id = tbl_file_structure.fk_structure_id)
                                              Filter: (fk_archive_id
= 56)
                                  ->  Seq Scan on tbl_computer
(cost=0.00..2.16 rows=1 width=20) (actual time=0.004..0.010 rows=1
loops=160)
                                        Filter:
((computer_name)::text = 'SOLARIS2'::text)
                            ->  Seq Scan on tbl_share
(cost=0.00..1.12 rows=12 width=29) (actual time=0.002..0.007 rows=12
loops=160)
                      ->  Bitmap Heap Scan on tbl_archive
(cost=2.59..6.60 rows=1 width=24) (actual time=0.007..0.008 rows=1
loops=160)
                            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=0.005..0.005 rows=1 loops=160)
                                  Index Cond: (56 = pk_archive_id)
                ->  Seq Scan on tbl_job  (cost=0.00..6.51 rows=51
width=16) (actual time=0.002..0.031 rows=51 loops=160)
          ->  Index Scan using tbl_job_group_pkey on tbl_job_group
(cost=0.00..4.42 rows=1 width=13) (actual time=0.003..0.004 rows=1
loops=160)
                Index Cond: (tbl_job.fk_job_group_id =
tbl_job_group.pk_job_group_id)
  Total runtime: 22898.840 ms

Thanks,
Henrik