Understanding EXPLAIN ANALYZE output - Mailing list pgsql-general

From Ed L.
Subject Understanding EXPLAIN ANALYZE output
Date
Msg-id 200502091100.00799.pgsql@bluepolka.net
Whole thread Raw
Responses Re: Understanding EXPLAIN ANALYZE output
Re: Understanding EXPLAIN ANALYZE output
List pgsql-general
I'm trying to optimize a large query by looking at
EXPLAIN ANALYZE output.  Here's what I think may be
the most relevant snippet:

    21 ->  Nested Loop  (cost=0.00..108.85 rows=1 width=1196) (actual time=4769.59..4769.59 rows=0 loops=1)
    22       ->  Nested Loop  (cost=0.00..64.78 rows=4 width=131) (actual time=0.41..72.80 rows=1014 loops=1)
    23             ->  Nested Loop  (cost=0.00..40.68 rows=4 width=103) (actual time=0.34..46.51 rows=1014 loops=1)
    24                   ->  Nested Loop  (cost=0.00..32.40 rows=3 width=52) (actual time=0.24..11.07 rows=689 loops=1)
    25                         ->  Index Scan using uc_review_reviewnum on review  (cost=0.00..3.85 rows=1 width=28)
(actualtime=0.12..0.13 rows=1 loops=1) 
    26                               Index Cond: (reviewnum = '1890382'::bpchar)
    27                         ->  Index Scan using idx_customerorder_review_key on customerorder  (cost=0.00..27.90
rows=52width=24) (actual time=0.11..8.07 rows=689 loops=1) 
    28                               Index Cond: ("outer"."key" = customerorder.review_key)
    29                               Filter: (ordertype = 'TEST'::bpchar)
    30                   ->  Index Scan using idx_occurrencehistory_customerorder_key on occurrencehistory
(cost=0.00..3.05rows=2 width=51) (actual time=0.02..0.04 rows=1 loops=689) 
    31                         Index Cond: ("outer"."key" = occurrencehistory.customerorder_key)
    32             ->  Index Scan using pk_user on user  (cost=0.00..5.80 rows=1 width=28) (actual time=0.01..0.01
rows=1loops=1014) 
    33                   Index Cond: ("outer".user_key = user."key")
    34       ->  Index Scan using idx_queryoutcome_occurrencehistory_key on queryoutcome  (cost=0.00..10.28 rows=28
width=1065)(actual time=4.63..4.63 rows=0 loops=1014) 
    35             Index Cond: ("outer"."key" = queryoutcome.occurrencehistory_key)
    36 ->  Index Scan using pk_querydefinition on querydefinition  (cost=0.00..5.99 rows=1 width=58) (never executed)
    37       Index Cond: ("outer".querydefinition_key = querydefinition."key")

If I understand these correctly, line 22's nested loop finished
returning the last row 72.80ms into the query, and then line
21's nested loop returns its 0 rows 4769.59ms into the query.
That would seem to mean 4696.79ms were spent executing the
nested loop on line 21 prior to returning the first row.

If I got that right, how do I figure out what constitutes the
nested loop of line 21?

TIA.

Ed


pgsql-general by date:

Previous
From: Shachar Shemesh
Date:
Subject: Re: ADO adCmdStoredProc PlPgSql-SP Parameters
Next
From: Roy Souther
Date:
Subject: EXTPROC External Procedure