Thread: Need help with understanding the explain analyze query plan

Need help with understanding the explain analyze query plan

From
Shubhra Sharma
Date:
I have this query: 
===================

WITH cte_calls AS (
         SELECT call_stream.*,
            
           cmr.some_columns
           
           FROM call_stream
      INNER JOIN cmr ON call_stream.cmr_id = cmr.id
        ), cte_phone_groups_calls AS (
         SELECT DISTINCT v_pg.phone_group_name,
            cte_calls.*
                       FROM cte_calls
      INNER JOIN v_pg
      ON 
   (cte_calls.company_id = v_pg.company_id) 
AND (v_pg.filtered_extension = cte_calls.party_1_extension::text AND v_pg.system_name = cte_calls.party_1_system_name::text) 
OR (v_pg.filtered_extension = cte_calls.party_2_extension::text AND v_pg.system_name = cte_calls.party_2_system_name::text)
        ), cte_media_src_calls AS (
         SELECT DISTINCT v_as.some_columns,
           
            cte_phone_groups_calls.some_columns
            
           FROM cte_phone_groups_calls
      LEFT JOIN v_as
ON 
cte_phone_groups_calls.config_id = v_as.sync_profile_id 
AND v_as.extension::text = cte_phone_groups_calls.party_1_extension::text 
AND v_as.system_name::text = cte_phone_groups_calls.party_1_system_name::text
     WHERE (cte_phone_groups_calls.source_ip::text 
IN ( SELECT v_as.ip_address FROM v_as WHERE v_as.vendor::text = 'BLAH'::text))
        ), cte_media_src_dest_calls AS (
         SELECT DISTINCT cte_media_src_calls.some_columns,
            v_as.some_columns
            
      LEFT JOIN v_as on
cte_media_src_calls.config_id = v_as.sync_profile_id 
AND v_as.extension::text = cte_media_src_calls.party_2_extension::text  
AND v_as.system_name::text = cte_media_src_calls.party_2_system_name::text
     WHERE (cte_media_src_calls.destination_ip::text IN ( SELECT v_as.ip_address
              FROM v_as
             WHERE v_as.vendor::text = 'BLAH'::text))
        )
 SELECT 
    cte_media_src_dest_calls.*
   FROM cte_media_src_dest_calls
======================================
when I run an explain analyse I see the following:

"CTE Scan on cte_media_src_dest_calls  (cost=231.73..231.75 rows=1 width=1080) (actual time=72.957..74.301 rows=120 loops=1)"
"  Buffers: shared hit=990"
"  CTE cte_calls"
"    ->  Hash Join  (cost=9.88..18.07 rows=85 width=377) (actual time=0.765..1.308 rows=99 loops=1)"
"          Hash Cond: (call_stream.cmr_id = avaya_cmr.cmr_id)"
"          Buffers: shared hit=12"
"          ->  Seq Scan on call_stream  (cost=0.00..6.70 rows=170 width=276) (actual time=0.011..0.230 rows=170 loops=1)"
"                Buffers: shared hit=5"
"          ->  Hash  (cost=8.28..8.28 rows=128 width=109) (actual time=0.623..0.623 rows=128 loops=1)"
"                Buckets: 1024  Batches: 1  Memory Usage: 11kB"
"                Buffers: shared hit=7"
"                ->  Seq Scan on avaya_cmr  (cost=0.00..8.28 rows=128 width=109) (actual time=0.008..0.332 rows=128 loops=1)"
"                      Buffers: shared hit=7"
"  CTE cte_phone_groups_calls"
"    ->  HashAggregate  (cost=191.76..191.77 rows=1 width=768) (actual time=25.626..25.932 rows=186 loops=1)"
"          Buffers: shared hit=16"
"          ->  Nested Loop  (cost=0.00..191.66 rows=1 width=768) (actual time=1.085..24.088 rows=306 loops=1)"
"                Join Filter: (((cte_calls.company_id = v_avaya_stations_by_phone_group.company_id) AND (v_avaya_stations_by_phone_group.filtered_extension = (cte_calls.party_1_extension)::text) AND ((v_avaya_stations_by_phone_group.system_name)::text = (ct (...)"
"                Rows Removed by Join Filter: 8307"
"                Buffers: shared hit=16"
"                ->  CTE Scan on cte_calls  (cost=0.00..1.70 rows=85 width=736) (actual time=0.772..1.782 rows=99 loops=1)"
"                      Buffers: shared hit=12"
"                ->  Materialize  (cost=0.00..5.30 rows=87 width=104) (actual time=0.001..0.097 rows=87 loops=99)"
"                      Buffers: shared hit=4"
"                      ->  Seq Scan on v_avaya_stations_by_phone_group  (cost=0.00..4.87 rows=87 width=104) (actual time=0.007..0.186 rows=87 loops=1)"
"                            Buffers: shared hit=4"
"  CTE cte_media_src_calls"
"    ->  HashAggregate  (cost=10.93..10.94 rows=1 width=796) (actual time=47.113..47.569 rows=172 loops=1)"
"          Buffers: shared hit=498"
"          ->  Nested Loop Semi Join  (cost=0.04..10.82 rows=1 width=796) (actual time=27.087..46.113 rows=172 loops=1)"
"                Join Filter: ((cte_phone_groups_calls.source_ip)::text = (v_reports_avaya_stations_1_1.ip_address)::text)"
"                Rows Removed by Join Filter: 5944"
"                Buffers: shared hit=498"
"                ->  Hash Right Join  (cost=0.04..5.32 rows=1 width=796) (actual time=27.072..27.670 rows=186 loops=1)"
"                      Hash Cond: ((v_reports_avaya_stations_1.avaya_sync_profile_id = cte_phone_groups_calls.config_id) AND ((v_reports_avaya_stations_1.extension)::text = (cte_phone_groups_calls.party_1_extension)::text) AND ((v_reports_avaya_stations_1.s (...)"
"                      Buffers: shared hit=20"
"                      ->  Seq Scan on v_reports_avaya_stations_1  (cost=0.00..4.60 rows=60 width=59) (actual time=0.004..0.054 rows=60 loops=1)"
"                            Buffers: shared hit=4"
"                      ->  Hash  (cost=0.02..0.02 rows=1 width=768) (actual time=27.030..27.030 rows=186 loops=1)"
"                            Buckets: 1024  Batches: 1  Memory Usage: 48kB"
"                            Buffers: shared hit=16"
"                            ->  CTE Scan on cte_phone_groups_calls  (cost=0.00..0.02 rows=1 width=768) (actual time=25.631..26.659 rows=186 loops=1)"
"                                  Buffers: shared hit=16"
"                ->  Seq Scan on v_reports_avaya_stations_1 v_reports_avaya_stations_1_1  (cost=0.00..4.75 rows=60 width=13) (actual time=0.002..0.050 rows=33 loops=186)"
"                      Filter: ((vendor)::text = 'AVAYA'::text)"
"                      Buffers: shared hit=478"
"  CTE cte_media_src_dest_calls"
"    ->  HashAggregate  (cost=10.95..10.96 rows=1 width=956) (actual time=72.943..73.292 rows=120 loops=1)"
"          Buffers: shared hit=990"
"          ->  Nested Loop Semi Join  (cost=0.04..10.82 rows=1 width=956) (actual time=49.311..71.990 rows=120 loops=1)"
"                Join Filter: ((cte_media_src_calls.destination_ip)::text = (v_reports_avaya_stations_1_1_1.ip_address)::text)"
"                Rows Removed by Join Filter: 6428"
"                Buffers: shared hit=990"
"                ->  Hash Right Join  (cost=0.04..5.32 rows=1 width=956) (actual time=49.289..49.999 rows=172 loops=1)"
"                      Hash Cond: ((v_reports_avaya_stations_1_2.avaya_sync_profile_id = cte_media_src_calls.config_id) AND ((v_reports_avaya_stations_1_2.extension)::text = (cte_media_src_calls.party_2_extension)::text) AND ((v_reports_avaya_stations_1_2.s (...)"
"                      Buffers: shared hit=502"
"                      ->  Seq Scan on v_reports_avaya_stations_1 v_reports_avaya_stations_1_2  (cost=0.00..4.60 rows=60 width=59) (actual time=0.005..0.103 rows=60 loops=1)"
"                            Buffers: shared hit=4"
"                      ->  Hash  (cost=0.02..0.02 rows=1 width=928) (actual time=49.228..49.228 rows=172 loops=1)"
"                            Buckets: 1024  Batches: 1  Memory Usage: 47kB"
"                            Buffers: shared hit=498"
"                            ->  CTE Scan on cte_media_src_calls  (cost=0.00..0.02 rows=1 width=928) (actual time=47.123..48.661 rows=172 loops=1)"
"                                  Buffers: shared hit=498"
"                ->  Seq Scan on v_reports_avaya_stations_1 v_reports_avaya_stations_1_1_1  (cost=0.00..4.75 rows=60 width=13) (actual time=0.003..0.064 rows=38 loops=172)"
"                      Filter: ((vendor)::text = 'AVAYA'::text)"
"                      Buffers: shared hit=488"
"Total runtime: 76.051 ms"
======================

I don't understand how to read  the output.

Re: Need help with understanding the explain analyze query plan

From
David G Johnston
Date:
ssharma wrote
> "Total runtime: 76.051 ms"
> ======================
>
> I don't understand how to read  the output.

I don't understand why you would want to...

There is considerable material on the internet about how to read plans,
including the documentation.  You're not that likely to get someone to try
teaching you about EXPLAIN using the query you've shown but if you show
you've done some reading and ask somewhat more specific questions you will
find people willing to help fill in the gaps.

Typically you would start with a query that is performing poorly and at
first glance 76ms doesn't seem bad enough to warrant any effort trying to
understand how the planner is fulfilling your query.

Though, to make reading plans easier you should consider using this site:

http://explain.depesz.com/

I'd suggest copying your explain output there, taking some time to review it
and do some reading (on that site, in the documentation, and elsewhere), and
then come back and ask some specific questions.

David J.




--
View this message in context:
http://postgresql.1045698.n5.nabble.com/Need-help-with-understanding-the-explain-analyze-query-plan-tp5824939p5824949.html
Sent from the PostgreSQL - novice mailing list archive at Nabble.com.