Understanding Postgres explain plan

Question

I am trying to understand a Postgres explain plan using this website (http://explain.depesz.com).

This is my plan:

Unique  (cost=795.43..800.89 rows=546 width=23) (actual time=0.599..0.755 rows=620 loops=1)
  ->  Sort  (cost=795.43..796.79 rows=546 width=23) (actual time=0.598..0.626 rows=620 loops=1)
        Sort Key: m.member_id, c.total_charged_amt DESC, c.claim_status
        Sort Method: quicksort  Memory: 73kB
        ->  Nested Loop  (cost=9.64..770.60 rows=546 width=23) (actual time=0.023..0.342 rows=620 loops=1)
              ->  Bitmap Heap Scan on member m  (cost=9.22..222.50 rows=63 width=8) (actual time=0.016..0.024 rows=62 loops=1)
                    Recheck Cond: (((member_id >= 1584161838) AND (member_id <= 1584161898)) OR (member_birth_dt = '1978-03-13'::date))
                    Heap Blocks: exact=3
                    ->  BitmapOr  (cost=9.22..9.22 rows=63 width=0) (actual time=0.013..0.013 rows=0 loops=1)
                          ->  Bitmap Index Scan on member_pkey  (cost=0.00..4.31 rows=2 width=0) (actual time=0.007..0.007 rows=61 loops=1)
                                Index Cond: ((member_id >= 1584161838) AND (member_id <= 1584161898))
                          ->  Bitmap Index Scan on idx_dob  (cost=0.00..4.88 rows=61 width=0) (actual time=0.006..0.006 rows=1 loops=1)
                                Index Cond: (member_birth_dt = '1978-03-13'::date)
              ->  Index Scan using idx_memberid on claim c  (cost=0.42..8.60 rows=10 width=23) (actual time=0.001..0.003 rows=10 loops=62)
                    Index Cond: (member_id = m.member_id)
Planning Time: 0.218 ms
Execution Time: 0.812 ms

The plan is also available in the following link: https://explain.depesz.com/s/Qzau.

I have following questions:

Bitmap Index Scans which runs in 0.007s and 0.006s respectively runs in parallel because of indentation.

So why does Bitmapor start at 0.013s? Why is it adding time of both its children? The start time of Bitmapor should be the maximum of its 2 children. So ideally the exclusive time of Bitmapor should be 0.006 (0.013-0.007), but it is 0 (0.013-0.007-0.006)
Bitmap Heap Scan and index scan are children of Nested Loop and run in 0.024s and 0.186s, respectively.

Because of the indentation I assume these 2 children run in parallel. So the parent exclusive time should be 0.156 (0.342-0.186), but instead it is 0.132(0.342-0.186-0.24).

My understanding is we should subtract maximum of the child timings (since they run in parallel) to get the exclusive time spent in the node. But instead it is adding up child timings and then subtracting the sum from the end time of the parent to get the exclusive time. Did i understand incorrectly about explain plans?

Any help is really appreciated as I am totally confused with interpreting them.

"runs in parallel because of indentation" - no, that's a wrong assumption. They run one after the other — user330315
– user330315, Commented May 7, 2020 at 7:31
Thanks @a_horse_with_no_name for your comment. If none of them runs parallel then why is there indentation? I was thinking all indented elements run in parallel. — sandeep007
– sandeep007, Commented May 7, 2020 at 8:25

Laurenz Albe · Accepted Answer · 2020-05-07 08:59:43Z

1

As the horse said, there is no parallel processing involved. If parallel query were involved, you would see a Gather node that collects the results.

The indentation visualizes the graph of the query execution plan:

                         Unique
                           |
                          Sort
                           |
                      Nested Loop
                        /      \
          Bitmap Heap Scan    Index Scan
                  |
              Bitmap Or
               /     \
Bitmap Index Scan   Bitmap Index Scan

That explains why explain.depesz.com calculates the exclusive time the way it does. Note that that is just a best effort, not the absolute truth, because (for example) a "bitmap or" does not take zero time. But explain.depesz.com can only go by the numbers it gets from EXPLAIN.

answered May 7, 2020 at 8:59

Laurenz Albe

257k22 gold badges312 silver badges388 bronze badges

Sign up to request clarification or add additional context in comments.

2 Comments

sandeep007 Over a year ago

Thankyou for your answer. I have another question. Why is there different count of rows in one of the node (546 vs 620). This is explain analyze output so no way it can be estimates. -> Nested Loop (cost=9.64..770.60 rows=546 width=23) (actual time=0.023..0.342 rows=620 loops=1)

Laurenz Albe Over a year ago

The first is the estimate, the second the reality.

Collectives™ on Stack Overflow

Understanding Postgres explain plan

1 Answer 1

2 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

2 Comments

Your Answer

Sign up or log in

Post as a guest

Related