Interpreting EXPLAIN ANALYSE - Mailing list pgsql-general

Greets,

I'm trying to figure out why the following SELECT has become slow (hardware,
code changes, etc) and would appreciate any comments on interpreting the
EXPLAIN ANALYZE output.  It *used* to take a few seconds at most, but not
anymore...  In figuring out which part is taking so long, what's the important
bit to examine (besides making sure indexes are being used)?  Presumably
"actual time="?

If I can identify which index is taking the longest from the output below,
then I can look at moving it to a faster TABLESPACE or something.


explain analyze
SELECT pl.sss, pl.did, pl.lid, pr.rank, plc.obl
       FROM plink pl LEFT JOIN prank pr USING (did)
       LEFT JOIN plink_count plc ON md5(plc.did)=md5(pr.did)
       LEFT JOIN snames s ON s.name=pl.sss
       WHERE
       s.bsit=0 AND s.disabled=0 AND
       s.prankignore=0 AND
       pl.lid = lower(E'stuff');




 Nested Loop Left Join  (cost=22717.85..40240.86 rows=47 width=177) (actual
time=532299.546..532385.533 rows=1 loops=1)
   ->  Nested Loop Left Join  (cost=22717.84..40055.65 rows=47 width=205)
(actual time=532299.546..532385.533 rows=1 loops=1)
         ->  Hash Join  (cost=22717.84..39936.36 rows=47 width=141) (actual
time=532297.546..532383.533 rows=1 loops=1)
               Hash Cond: (pl.sss = s.name)
               ->  Index Scan using sk_plink3 on plink pl
(cost=0.00..17155.35 rows=16718 width=141) (actual
time=0.000..0.000 rows=1 loops=1)
                     Index Cond: (lid = 'stuff'::text)
               ->  Hash  (cost=22717.57..22717.57 rows=22 width=32) (actual
time=461886.321..461886.321 rows=164147851 loops=1)
                     Buckets: 1024  Batches: 8 (originally 1)  Memory Usage:
1548289kB
                     ->  Bitmap Heap Scan on snames s
(cost=18260.53..22717.57 rows=22 width=32) (actual
time=45939.971..351687.125 rows=164147851 loops=1)
                           Recheck Cond: ((bsit = 0) AND (prankignore = 0))
                           Filter: (disabled = 0)
                           ->  BitmapAnd  (cost=18260.53..18260.53 rows=4455
width=0) (actual time=43802.298..43802.298 rows=0
loops=1)
                               ->  Bitmap Index Scan on snames7
(cost=0.00..9130.13 rows=890933 width=0)
(actual time=20285.896..20285.896
rows=178144776 loops=1)
                                       Index Cond: (bsit = 0)
                                 ->  Bitmap Index Scan on sk_snames20
(cost=0.00..9130.13 rows=890933 width=0)
(actual time=22245.596..22245.596
rows=178186036 loops=1)
                                       Index Cond: (prankignore = 0)
         ->  Index Scan using sk_prank on prank pr  (cost=0.00..2.53 rows=1
width=64) (actual time=2.000..2.000 rows=0 loops=1)
               Index Cond: (pl.did = pr.did)
   ->  Index Scan using skplink_count0 on plink_count plc  (cost=0.00..3.92
rows=1 width=36) (actual time=0.000..0.000 rows=0 loops=1)
         Index Cond: (md5(plc.did) = md5(pr.did))
 Total runtime: 532386.533 ms


Thanks
Henry