Search Postgresql Archives

Re: Why does explain differ from explan analyze?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Tom,

On Wed, 2006-12-06 at 14:48 -0500, Tom Lane wrote:
> Joost Kraaijeveld <J.Kraaijeveld@xxxxxxxxxx> writes:
> > I have a query that if I do "explain" shows an other plan than if I do
> > "explain analyze" with that same query (immediately after the explain).
> 
> Really?  What PG version is this?  Can you provide a self-contained
> test case?
Yes, really ;-). 

PostgreSQL 8.1.5 on Windows XP.

Alas, no self contained test case, I do have the query, the "explain"
and the "explain analyse" output. Sorry about the long text.

SELECT *
FROM   deliver_cares t0_$deliver_cares 
LEFT   OUTER JOIN cares t1_$deliver_cares_care                          ON t0_$deliver_cares.care_id=t1_$deliver_cares_care.care_id 
LEFT   OUTER JOIN components t2_$deliver_cares_care_component           ON t1_$deliver_cares_care.component_id=t2_$deliver_cares_care_component.component_id 
LEFT   OUTER JOIN indication_functions t3_$deliver_cares_care_indicatio ON t1_$deliver_cares_care.indication_function_id=t3_$deliver_cares_care_indicatio.indication_function_id 
LEFT   OUTER JOIN indications t4_$deliver_cares_care_indicatio          ON t3_$deliver_cares_care_indicatio.indication_id=t4_$deliver_cares_care_indicatio.indication_id 
LEFT   OUTER JOIN patients t5_$deliver_cares_care_indicatio             ON t4_$deliver_cares_care_indicatio.patient_id=t5_$deliver_cares_care_indicatio.patient_id 
LEFT   OUTER JOIN org_personnels t6_$deliver_cares_registeredOrgP       ON t0_$deliver_cares.registered_org_personnel_id=t6_$deliver_cares_registeredOrgP.org_personnel_id 
LEFT   OUTER JOIN org_personnels t7_$deliver_cares_assignedOrgPer       ON t0_$deliver_cares.assigned_org_personnel_id=t7_$deliver_cares_assignedOrgPer.org_personnel_id, timeframes t1_pdam__$deliver_cares_timeframe 
WHERE  ((    (    (    (    (    (    (    (    (t4_$deliver_cares_care_indicatio.patient_id = 21)                   -- pdam
                                                 AND (t0_$deliver_cares.deliver_date >= current_date - 200)          -- pdam
                                            ) 
                                        AND (t0_$deliver_cares.deliver_date < current_date)                          -- pdam
                                       ) 
                                   AND (t0_$deliver_cares.timeframe_id = 45)                                         -- pdam
                                  ) 
                              AND (t1_$deliver_cares_care.workers_number = 1)                                        -- pdam
                             ) 
                         AND (t0_$deliver_cares.status = 'P')                                                        -- pdam
                        )
                    AND (t1_$deliver_cares_care.status <> 'S')                                                       -- pdam
                   ) 
               AND (t0_$deliver_cares.assigned_org_personnel_id IS NULL)
              ) 
          AND t0_$deliver_cares.care_id=t1_$deliver_cares_care.care_id 
          AND t1_$deliver_cares_care.indication_function_id=t3_$deliver_cares_care_indicatio.indication_function_id 
          AND t3_$deliver_cares_care_indicatio.indication_id=t4_$deliver_cares_care_indicatio.indication_id
       )) 
AND    t0_$deliver_cares.timeframe_id=t1_pdam__$deliver_cares_timeframe.timeframe_id 
ORDER  BY t0_$deliver_cares.deliver_date ASC
,         t1_pdam__$deliver_cares_timeframe.start_time ASC

explain:

--------------
Sort  (cost=38222.31..38222.49 rows=71 width=3089)
  Sort Key: "t0_$deliver_cares".deliver_date, "t1_pdam__$deliver_cares_timeframe".start_time
  ->  Nested Loop  (cost=1457.34..38220.13 rows=71 width=3089)
        ->  Seq Scan on timeframes "t1_pdam__$deliver_cares_timeframe"  (cost=0.00..1.25 rows=1 width=126)
              Filter: (timeframe_id = 45)
        ->  Nested Loop Left Join  (cost=1457.34..38218.17 rows=71 width=2963)
              ->  Nested Loop Left Join  (cost=1457.34..37803.85 rows=71 width=2175)
                    ->  Hash Left Join  (cost=1457.34..37389.53 rows=71 width=1387)
                          Hash Cond: ("outer".patient_id = "inner".patient_id)
                          ->  Hash Join  (cost=1451.54..37383.36 rows=71 width=486)
                                Hash Cond: ("outer".indication_function_id = "inner".indication_function_id)
                                ->  Hash Left Join  (cost=1438.21..37258.40 rows=22198 width=323)
                                      Hash Cond: ("outer".component_id = "inner".component_id)
                                      ->  Hash Join  (cost=1409.91..36897.13 rows=22198 width=233)
                                            Hash Cond: ("outer".care_id = "inner".care_id)
                                            ->  Bitmap Heap Scan on deliver_cares "t0_$deliver_cares"  (cost=1249.99..36124.88 rows=39035 width=105)
                                                  Recheck Cond: (timeframe_id = 45)
                                                  Filter: ((deliver_date >= (('now'::text)::date - 200)) AND (deliver_date < ('now'::text)::date) AND ((status)::text = 'P'::text) AND (assigned_org_personnel_id IS NULL))
                                                  ->  Bitmap Index Scan on idx_deliver_cares2  (cost=0.00..1249.99 rows=199996 width=0)
                                                        Index Cond: (timeframe_id = 45)
                                            ->  Hash  (cost=152.40..152.40 rows=3010 width=128)
                                                  ->  Seq Scan on cares "t1_$deliver_cares_care"  (cost=0.00..152.40 rows=3010 width=128)
                                                        Filter: ((workers_number = 1) AND ((status)::text <> 'S'::text))
                                      ->  Hash  (cost=25.84..25.84 rows=984 width=90)
                                            ->  Seq Scan on components "t2_$deliver_cares_care_component"  (cost=0.00..25.84 rows=984 width=90)
                                ->  Hash  (cost=13.32..13.32 rows=5 width=163)
                                      ->  Nested Loop  (cost=0.00..13.32 rows=5 width=163)
                                            ->  Index Scan using idx_indications_patient_id on indications "t4_$deliver_cares_care_indicatio"  (cost=0.00..4.33 rows=2 width=97)
                                                  Index Cond: (patient_id = 21)
                                            ->  Index Scan using idx_indication_functions1 on indication_functions "t3_$deliver_cares_care_indicatio"  (cost=0.00..4.45 rows=4 width=66)
                                                  Index Cond: ("t3_$deliver_cares_care_indicatio".indication_id = "outer".indication_id)
                          ->  Hash  (cost=5.80..5.80 rows=1 width=901)
                                ->  Index Scan using idx_patients_human_id_pk on patients "t5_$deliver_cares_care_indicatio"  (cost=0.00..5.80 rows=1 width=901)
                                      Index Cond: (patient_id = 21)
                    ->  Index Scan using idx_org_personnels2 on org_personnels "t6_$deliver_cares_registeredorgp"  (cost=0.00..5.82 rows=1 width=788)
                          Index Cond: ("outer".registered_org_personnel_id = "t6_$deliver_cares_registeredorgp".org_personnel_id)
              ->  Index Scan using idx_org_personnels2 on org_personnels "t7_$deliver_cares_assignedorgper"  (cost=0.00..5.82 rows=1 width=788)
                    Index Cond: ("outer".assigned_org_personnel_id = "t7_$deliver_cares_assignedorgper".org_personnel_id)


explain analyse:
--------------
Sort  (cost=19067.67..19067.71 rows=17 width=3089) (actual time=634.660..634.746 rows=213 loops=1)
  Sort Key: "t0_$deliver_cares".deliver_date, "t1_pdam__$deliver_cares_timeframe".start_time
  ->  Nested Loop  (cost=18554.38..19067.32 rows=17 width=3089) (actual time=539.634..622.249 rows=213 loops=1)
        ->  Seq Scan on timeframes "t1_pdam__$deliver_cares_timeframe"  (cost=0.00..1.25 rows=1 width=126) (actual time=0.034..0.044 rows=1 loops=1)
              Filter: (timeframe_id = 45)
        ->  Nested Loop Left Join  (cost=18554.38..19065.90 rows=17 width=2963) (actual time=539.572..621.726 rows=213 loops=1)
              ->  Nested Loop Left Join  (cost=18554.38..18966.69 rows=17 width=2175) (actual time=539.564..620.846 rows=213 loops=1)
                    ->  Hash Left Join  (cost=18554.38..18867.49 rows=17 width=1387) (actual time=539.470..618.554 rows=213 loops=1)
                          Hash Cond: ("outer".patient_id = "inner".patient_id)
                          ->  Hash Join  (cost=18548.57..18861.59 rows=17 width=486) (actual time=539.219..617.703 rows=213 loops=1)
                                Hash Cond: ("outer".indication_function_id = "inner".indication_function_id)
                                ->  Hash Left Join  (cost=18530.09..18825.31 rows=3528 width=323) (actual time=530.610..608.155 rows=15831 loops=1)
                                      Hash Cond: ("outer".component_id = "inner".component_id)
                                      ->  Merge Join  (cost=18501.79..18744.09 rows=3528 width=233) (actual time=528.732..577.502 rows=15831 loops=1)
                                            Merge Cond: ("outer".care_id = "inner".care_id)
                                            ->  Index Scan using idx_cares7 on cares "t1_$deliver_cares_care"  (cost=0.00..176.05 rows=5147 width=128) (actual time=0.111..8.450 rows=4425 loops=1)
                                                  Filter: ((workers_number = 1) AND ((status)::text <> 'P'::text))
                                            ->  Sort  (cost=18501.79..18510.86 rows=3628 width=105) (actual time=528.570..541.792 rows=15940 loops=1)
                                                  Sort Key: "t0_$deliver_cares".care_id
                                                  ->  Bitmap Heap Scan on deliver_cares "t0_$deliver_cares"  (cost=8015.77..18287.28 rows=3628 width=105) (actual time=366.358..444.921 rows=15940 loops=1)
                                                        Recheck Cond: (((status)::text = 'D'::text) AND (timeframe_id = 45) AND (deliver_date >= (('now'::text)::date - 200)) AND (deliver_date < ('now'::text)::date))
                                                        Filter: (assigned_org_personnel_id IS NULL)
                                                        ->  BitmapAnd  (cost=8015.77..8015.77 rows=3628 width=0) (actual time=365.036..365.036 rows=0 loops=1)
                                                              ->  Bitmap Index Scan on idx_deliver_cares_status  (cost=0.00..1139.70 rows=182200 width=0) (actual time=67.510..67.510 rows=205223 loops=1)
                                                                    Index Cond: ((status)::text = 'D'::text)
                                                              ->  Bitmap Index Scan on idx_deliver_cares2  (cost=0.00..1249.99 rows=199996 width=0) (actual time=52.794..52.794 rows=182332 loops=1)
                                                                    Index Cond: (timeframe_id = 45)
                                                              ->  Bitmap Index Scan on idx_deliver_cares_deliver_date  (cost=0.00..5625.58 rows=643595 width=0) (actual time=240.958..240.958 rows=674086 loops=1)
                                                                    Index Cond: ((deliver_date >= (('now'::text)::date - 200)) AND (deliver_date < ('now'::text)::date))
                                      ->  Hash  (cost=25.84..25.84 rows=984 width=90) (actual time=1.811..1.811 rows=994 loops=1)
                                            ->  Seq Scan on components "t2_$deliver_cares_care_component"  (cost=0.00..25.84 rows=984 width=90) (actual time=0.054..1.024 rows=994 loops=1)
                                ->  Hash  (cost=18.46..18.46 rows=8 width=163) (actual time=0.821..0.821 rows=8 loops=1)
                                      ->  Nested Loop  (cost=0.00..18.46 rows=8 width=163) (actual time=0.643..0.780 rows=8 loops=1)
                                            ->  Index Scan using idx_indications_patient_id on indications "t4_$deliver_cares_care_indicatio"  (cost=0.00..4.98 rows=3 width=97) (actual time=0.310..0.349 rows=3 loops=1)
                                                  Index Cond: (patient_id = 12)
                                            ->  Index Scan using idx_indication_functions1 on indication_functions "t3_$deliver_cares_care_indicatio"  (cost=0.00..4.45 rows=4 width=66) (actual time=0.114..0.130 rows=3 loops=3)
                                                  Index Cond: ("t3_$deliver_cares_care_indicatio".indication_id = "outer".indication_id)
                          ->  Hash  (cost=5.80..5.80 rows=1 width=901) (actual time=0.205..0.205 rows=1 loops=1)
                                ->  Index Scan using idx_patients_human_id_pk on patients "t5_$deliver_cares_care_indicatio"  (cost=0.00..5.80 rows=1 width=901) (actual time=0.194..0.196 rows=1 loops=1)
                                      Index Cond: (patient_id = 12)
                    ->  Index Scan using idx_org_personnels2 on org_personnels "t6_$deliver_cares_registeredorgp"  (cost=0.00..5.82 rows=1 width=788) (actual time=0.005..0.006 rows=1 loops=213)
                          Index Cond: ("outer".registered_org_personnel_id = "t6_$deliver_cares_registeredorgp".org_personnel_id)
              ->  Index Scan using idx_org_personnels2 on org_personnels "t7_$deliver_cares_assignedorgper"  (cost=0.00..5.82 rows=1 width=788) (actual time=0.001..0.001 rows=0 loops=213)
                    Index Cond: ("outer".assigned_org_personnel_id = "t7_$deliver_cares_assignedorgper".org_personnel_id)
Total runtime: 639.205 ms


> > Does it have to do something with vacuum?
> 
> In theory an autovacuum happening between the two steps could update the
> statistics and cause the plan to change, but if it's repeatable then
> that hardly seems like the explanation.
It is repeatable, and no no vacuum is done.

-- 
Groeten,

Joost Kraaijeveld
Askesis B.V.
Molukkenstraat 14
6524NB Nijmegen
tel: 024-3888063 / 06-51855277
fax: 024-3608416
web: www.askesis.nl


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Postgresql Jobs]     [Postgresql Admin]     [Postgresql Performance]     [Linux Clusters]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Postgresql & PHP]     [Yosemite]
  Powered by Linux