]> begriffs open source - ai-pg/blob - full-docs/txt/using-explain.txt
Convert HTML docs to more streamlined TXT
[ai-pg] / full-docs / txt / using-explain.txt
1
2 14.1. Using EXPLAIN #
3
4    14.1.1. EXPLAIN Basics
5    14.1.2. EXPLAIN ANALYZE
6    14.1.3. Caveats
7
8    PostgreSQL devises a query plan for each query it receives. Choosing
9    the right plan to match the query structure and the properties of the
10    data is absolutely critical for good performance, so the system
11    includes a complex planner that tries to choose good plans. You can use
12    the EXPLAIN command to see what query plan the planner creates for any
13    query. Plan-reading is an art that requires some experience to master,
14    but this section attempts to cover the basics.
15
16    Examples in this section are drawn from the regression test database
17    after doing a VACUUM ANALYZE, using v18 development sources. You should
18    be able to get similar results if you try the examples yourself, but
19    your estimated costs and row counts might vary slightly because
20    ANALYZE's statistics are random samples rather than exact, and because
21    costs are inherently somewhat platform-dependent.
22
23    The examples use EXPLAIN's default “text” output format, which is
24    compact and convenient for humans to read. If you want to feed
25    EXPLAIN's output to a program for further analysis, you should use one
26    of its machine-readable output formats (XML, JSON, or YAML) instead.
27
28 14.1.1. EXPLAIN Basics #
29
30    The structure of a query plan is a tree of plan nodes. Nodes at the
31    bottom level of the tree are scan nodes: they return raw rows from a
32    table. There are different types of scan nodes for different table
33    access methods: sequential scans, index scans, and bitmap index scans.
34    There are also non-table row sources, such as VALUES clauses and
35    set-returning functions in FROM, which have their own scan node types.
36    If the query requires joining, aggregation, sorting, or other
37    operations on the raw rows, then there will be additional nodes above
38    the scan nodes to perform these operations. Again, there is usually
39    more than one possible way to do these operations, so different node
40    types can appear here too. The output of EXPLAIN has one line for each
41    node in the plan tree, showing the basic node type plus the cost
42    estimates that the planner made for the execution of that plan node.
43    Additional lines might appear, indented from the node's summary line,
44    to show additional properties of the node. The very first line (the
45    summary line for the topmost node) has the estimated total execution
46    cost for the plan; it is this number that the planner seeks to
47    minimize.
48
49    Here is a trivial example, just to show what the output looks like:
50 EXPLAIN SELECT * FROM tenk1;
51
52                          QUERY PLAN
53 -------------------------------------------------------------
54  Seq Scan on tenk1  (cost=0.00..445.00 rows=10000 width=244)
55
56    Since this query has no WHERE clause, it must scan all the rows of the
57    table, so the planner has chosen to use a simple sequential scan plan.
58    The numbers that are quoted in parentheses are (left to right):
59      * Estimated start-up cost. This is the time expended before the
60        output phase can begin, e.g., time to do the sorting in a sort
61        node.
62      * Estimated total cost. This is stated on the assumption that the
63        plan node is run to completion, i.e., all available rows are
64        retrieved. In practice a node's parent node might stop short of
65        reading all available rows (see the LIMIT example below).
66      * Estimated number of rows output by this plan node. Again, the node
67        is assumed to be run to completion.
68      * Estimated average width of rows output by this plan node (in
69        bytes).
70
71    The costs are measured in arbitrary units determined by the planner's
72    cost parameters (see Section 19.7.2). Traditional practice is to
73    measure the costs in units of disk page fetches; that is, seq_page_cost
74    is conventionally set to 1.0 and the other cost parameters are set
75    relative to that. The examples in this section are run with the default
76    cost parameters.
77
78    It's important to understand that the cost of an upper-level node
79    includes the cost of all its child nodes. It's also important to
80    realize that the cost only reflects things that the planner cares
81    about. In particular, the cost does not consider the time spent to
82    convert output values to text form or to transmit them to the client,
83    which could be important factors in the real elapsed time; but the
84    planner ignores those costs because it cannot change them by altering
85    the plan. (Every correct plan will output the same row set, we trust.)
86
87    The rows value is a little tricky because it is not the number of rows
88    processed or scanned by the plan node, but rather the number emitted by
89    the node. This is often less than the number scanned, as a result of
90    filtering by any WHERE-clause conditions that are being applied at the
91    node. Ideally the top-level rows estimate will approximate the number
92    of rows actually returned, updated, or deleted by the query.
93
94    Returning to our example:
95 EXPLAIN SELECT * FROM tenk1;
96
97                          QUERY PLAN
98 -------------------------------------------------------------
99  Seq Scan on tenk1  (cost=0.00..445.00 rows=10000 width=244)
100
101    These numbers are derived very straightforwardly. If you do:
102 SELECT relpages, reltuples FROM pg_class WHERE relname = 'tenk1';
103
104    you will find that tenk1 has 345 disk pages and 10000 rows. The
105    estimated cost is computed as (disk pages read * seq_page_cost) + (rows
106    scanned * cpu_tuple_cost). By default, seq_page_cost is 1.0 and
107    cpu_tuple_cost is 0.01, so the estimated cost is (345 * 1.0) + (10000 *
108    0.01) = 445.
109
110    Now let's modify the query to add a WHERE condition:
111 EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 7000;
112
113                          QUERY PLAN
114 ------------------------------------------------------------
115  Seq Scan on tenk1  (cost=0.00..470.00 rows=7000 width=244)
116    Filter: (unique1 < 7000)
117
118    Notice that the EXPLAIN output shows the WHERE clause being applied as
119    a “filter” condition attached to the Seq Scan plan node. This means
120    that the plan node checks the condition for each row it scans, and
121    outputs only the ones that pass the condition. The estimate of output
122    rows has been reduced because of the WHERE clause. However, the scan
123    will still have to visit all 10000 rows, so the cost hasn't decreased;
124    in fact it has gone up a bit (by 10000 * cpu_operator_cost, to be
125    exact) to reflect the extra CPU time spent checking the WHERE
126    condition.
127
128    The actual number of rows this query would select is 7000, but the rows
129    estimate is only approximate. If you try to duplicate this experiment,
130    you may well get a slightly different estimate; moreover, it can change
131    after each ANALYZE command, because the statistics produced by ANALYZE
132    are taken from a randomized sample of the table.
133
134    Now, let's make the condition more restrictive:
135 EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 100;
136
137                                   QUERY PLAN
138 -------------------------------------------------------------------​-----------
139  Bitmap Heap Scan on tenk1  (cost=5.06..224.98 rows=100 width=244)
140    Recheck Cond: (unique1 < 100)
141    ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100 width=0)
142          Index Cond: (unique1 < 100)
143
144    Here the planner has decided to use a two-step plan: the child plan
145    node visits an index to find the locations of rows matching the index
146    condition, and then the upper plan node actually fetches those rows
147    from the table itself. Fetching rows separately is much more expensive
148    than reading them sequentially, but because not all the pages of the
149    table have to be visited, this is still cheaper than a sequential scan.
150    (The reason for using two plan levels is that the upper plan node sorts
151    the row locations identified by the index into physical order before
152    reading them, to minimize the cost of separate fetches. The “bitmap”
153    mentioned in the node names is the mechanism that does the sorting.)
154
155    Now let's add another condition to the WHERE clause:
156 EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 100 AND stringu1 = 'xxx';
157
158                                   QUERY PLAN
159 -------------------------------------------------------------------​-----------
160  Bitmap Heap Scan on tenk1  (cost=5.04..225.20 rows=1 width=244)
161    Recheck Cond: (unique1 < 100)
162    Filter: (stringu1 = 'xxx'::name)
163    ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100 width=0)
164          Index Cond: (unique1 < 100)
165
166    The added condition stringu1 = 'xxx' reduces the output row count
167    estimate, but not the cost because we still have to visit the same set
168    of rows. That's because the stringu1 clause cannot be applied as an
169    index condition, since this index is only on the unique1 column.
170    Instead it is applied as a filter on the rows retrieved using the
171    index. Thus the cost has actually gone up slightly to reflect this
172    extra checking.
173
174    In some cases the planner will prefer a “simple” index scan plan:
175 EXPLAIN SELECT * FROM tenk1 WHERE unique1 = 42;
176
177                                  QUERY PLAN
178 -------------------------------------------------------------------​----------
179  Index Scan using tenk1_unique1 on tenk1  (cost=0.29..8.30 rows=1 width=244)
180    Index Cond: (unique1 = 42)
181
182    In this type of plan the table rows are fetched in index order, which
183    makes them even more expensive to read, but there are so few that the
184    extra cost of sorting the row locations is not worth it. You'll most
185    often see this plan type for queries that fetch just a single row. It's
186    also often used for queries that have an ORDER BY condition that
187    matches the index order, because then no extra sorting step is needed
188    to satisfy the ORDER BY. In this example, adding ORDER BY unique1 would
189    use the same plan because the index already implicitly provides the
190    requested ordering.
191
192    The planner may implement an ORDER BY clause in several ways. The above
193    example shows that such an ordering clause may be implemented
194    implicitly. The planner may also add an explicit Sort step:
195 EXPLAIN SELECT * FROM tenk1 ORDER BY unique1;
196
197                             QUERY PLAN
198 -------------------------------------------------------------------
199  Sort  (cost=1109.39..1134.39 rows=10000 width=244)
200    Sort Key: unique1
201    ->  Seq Scan on tenk1  (cost=0.00..445.00 rows=10000 width=244)
202
203    If a part of the plan guarantees an ordering on a prefix of the
204    required sort keys, then the planner may instead decide to use an
205    Incremental Sort step:
206 EXPLAIN SELECT * FROM tenk1 ORDER BY hundred, ten LIMIT 100;
207
208                                               QUERY PLAN
209 -------------------------------------------------------------------​------------
210 -----------------
211  Limit  (cost=19.35..39.49 rows=100 width=244)
212    ->  Incremental Sort  (cost=19.35..2033.39 rows=10000 width=244)
213          Sort Key: hundred, ten
214          Presorted Key: hundred
215          ->  Index Scan using tenk1_hundred on tenk1  (cost=0.29..1574.20 rows=1
216 0000 width=244)
217
218    Compared to regular sorts, sorting incrementally allows returning
219    tuples before the entire result set has been sorted, which particularly
220    enables optimizations with LIMIT queries. It may also reduce memory
221    usage and the likelihood of spilling sorts to disk, but it comes at the
222    cost of the increased overhead of splitting the result set into
223    multiple sorting batches.
224
225    If there are separate indexes on several of the columns referenced in
226    WHERE, the planner might choose to use an AND or OR combination of the
227    indexes:
228 EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 100 AND unique2 > 9000;
229
230                                      QUERY PLAN
231 -------------------------------------------------------------------​------------
232 ------
233  Bitmap Heap Scan on tenk1  (cost=25.07..60.11 rows=10 width=244)
234    Recheck Cond: ((unique1 < 100) AND (unique2 > 9000))
235    ->  BitmapAnd  (cost=25.07..25.07 rows=10 width=0)
236          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100 width
237 =0)
238                Index Cond: (unique1 < 100)
239          ->  Bitmap Index Scan on tenk1_unique2  (cost=0.00..19.78 rows=999 widt
240 h=0)
241                Index Cond: (unique2 > 9000)
242
243    But this requires visiting both indexes, so it's not necessarily a win
244    compared to using just one index and treating the other condition as a
245    filter. If you vary the ranges involved you'll see the plan change
246    accordingly.
247
248    Here is an example showing the effects of LIMIT:
249 EXPLAIN SELECT * FROM tenk1 WHERE unique1 < 100 AND unique2 > 9000 LIMIT 2;
250
251                                      QUERY PLAN
252 -------------------------------------------------------------------​------------
253 ------
254  Limit  (cost=0.29..14.28 rows=2 width=244)
255    ->  Index Scan using tenk1_unique2 on tenk1  (cost=0.29..70.27 rows=10 width=
256 244)
257          Index Cond: (unique2 > 9000)
258          Filter: (unique1 < 100)
259
260    This is the same query as above, but we added a LIMIT so that not all
261    the rows need be retrieved, and the planner changed its mind about what
262    to do. Notice that the total cost and row count of the Index Scan node
263    are shown as if it were run to completion. However, the Limit node is
264    expected to stop after retrieving only a fifth of those rows, so its
265    total cost is only a fifth as much, and that's the actual estimated
266    cost of the query. This plan is preferred over adding a Limit node to
267    the previous plan because the Limit could not avoid paying the startup
268    cost of the bitmap scan, so the total cost would be something over 25
269    units with that approach.
270
271    Let's try joining two tables, using the columns we have been
272    discussing:
273 EXPLAIN SELECT *
274 FROM tenk1 t1, tenk2 t2
275 WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
276
277                                       QUERY PLAN
278 -------------------------------------------------------------------​------------
279 -------
280  Nested Loop  (cost=4.65..118.50 rows=10 width=488)
281    ->  Bitmap Heap Scan on tenk1 t1  (cost=4.36..39.38 rows=10 width=244)
282          Recheck Cond: (unique1 < 10)
283          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..4.36 rows=10 width=
284 0)
285                Index Cond: (unique1 < 10)
286    ->  Index Scan using tenk2_unique2 on tenk2 t2  (cost=0.29..7.90 rows=1 width
287 =244)
288          Index Cond: (unique2 = t1.unique2)
289
290    In this plan, we have a nested-loop join node with two table scans as
291    inputs, or children. The indentation of the node summary lines reflects
292    the plan tree structure. The join's first, or “outer”, child is a
293    bitmap scan similar to those we saw before. Its cost and row count are
294    the same as we'd get from SELECT ... WHERE unique1 < 10 because we are
295    applying the WHERE clause unique1 < 10 at that node. The t1.unique2 =
296    t2.unique2 clause is not relevant yet, so it doesn't affect the row
297    count of the outer scan. The nested-loop join node will run its second,
298    or “inner” child once for each row obtained from the outer child.
299    Column values from the current outer row can be plugged into the inner
300    scan; here, the t1.unique2 value from the outer row is available, so we
301    get a plan and costs similar to what we saw above for a simple SELECT
302    ... WHERE t2.unique2 = constant case. (The estimated cost is actually a
303    bit lower than what was seen above, as a result of caching that's
304    expected to occur during the repeated index scans on t2.) The costs of
305    the loop node are then set on the basis of the cost of the outer scan,
306    plus one repetition of the inner scan for each outer row (10 * 7.90,
307    here), plus a little CPU time for join processing.
308
309    In this example the join's output row count is the same as the product
310    of the two scans' row counts, but that's not true in all cases because
311    there can be additional WHERE clauses that mention both tables and so
312    can only be applied at the join point, not to either input scan. Here's
313    an example:
314 EXPLAIN SELECT *
315 FROM tenk1 t1, tenk2 t2
316 WHERE t1.unique1 < 10 AND t2.unique2 < 10 AND t1.hundred < t2.hundred;
317
318                                          QUERY PLAN
319 -------------------------------------------------------------------​------------
320 --------------
321  Nested Loop  (cost=4.65..49.36 rows=33 width=488)
322    Join Filter: (t1.hundred < t2.hundred)
323    ->  Bitmap Heap Scan on tenk1 t1  (cost=4.36..39.38 rows=10 width=244)
324          Recheck Cond: (unique1 < 10)
325          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..4.36 rows=10 width=
326 0)
327                Index Cond: (unique1 < 10)
328    ->  Materialize  (cost=0.29..8.51 rows=10 width=244)
329          ->  Index Scan using tenk2_unique2 on tenk2 t2  (cost=0.29..8.46 rows=1
330 0 width=244)
331                Index Cond: (unique2 < 10)
332
333    The condition t1.hundred < t2.hundred can't be tested in the
334    tenk2_unique2 index, so it's applied at the join node. This reduces the
335    estimated output row count of the join node, but does not change either
336    input scan.
337
338    Notice that here the planner has chosen to “materialize” the inner
339    relation of the join, by putting a Materialize plan node atop it. This
340    means that the t2 index scan will be done just once, even though the
341    nested-loop join node needs to read that data ten times, once for each
342    row from the outer relation. The Materialize node saves the data in
343    memory as it's read, and then returns the data from memory on each
344    subsequent pass.
345
346    When dealing with outer joins, you might see join plan nodes with both
347    “Join Filter” and plain “Filter” conditions attached. Join Filter
348    conditions come from the outer join's ON clause, so a row that fails
349    the Join Filter condition could still get emitted as a null-extended
350    row. But a plain Filter condition is applied after the outer-join rules
351    and so acts to remove rows unconditionally. In an inner join there is
352    no semantic difference between these types of filters.
353
354    If we change the query's selectivity a bit, we might get a very
355    different join plan:
356 EXPLAIN SELECT *
357 FROM tenk1 t1, tenk2 t2
358 WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2;
359
360                                         QUERY PLAN
361 -------------------------------------------------------------------​------------
362 -----------
363  Hash Join  (cost=226.23..709.73 rows=100 width=488)
364    Hash Cond: (t2.unique2 = t1.unique2)
365    ->  Seq Scan on tenk2 t2  (cost=0.00..445.00 rows=10000 width=244)
366    ->  Hash  (cost=224.98..224.98 rows=100 width=244)
367          ->  Bitmap Heap Scan on tenk1 t1  (cost=5.06..224.98 rows=100 width=244
368 )
369                Recheck Cond: (unique1 < 100)
370                ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100
371  width=0)
372                      Index Cond: (unique1 < 100)
373
374    Here, the planner has chosen to use a hash join, in which rows of one
375    table are entered into an in-memory hash table, after which the other
376    table is scanned and the hash table is probed for matches to each row.
377    Again note how the indentation reflects the plan structure: the bitmap
378    scan on tenk1 is the input to the Hash node, which constructs the hash
379    table. That's then returned to the Hash Join node, which reads rows
380    from its outer child plan and searches the hash table for each one.
381
382    Another possible type of join is a merge join, illustrated here:
383 EXPLAIN SELECT *
384 FROM tenk1 t1, onek t2
385 WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2;
386
387                                         QUERY PLAN
388 -------------------------------------------------------------------​------------
389 -----------
390  Merge Join  (cost=0.56..233.49 rows=10 width=488)
391    Merge Cond: (t1.unique2 = t2.unique2)
392    ->  Index Scan using tenk1_unique2 on tenk1 t1  (cost=0.29..643.28 rows=100 w
393 idth=244)
394          Filter: (unique1 < 100)
395    ->  Index Scan using onek_unique2 on onek t2  (cost=0.28..166.28 rows=1000 wi
396 dth=244)
397
398    Merge join requires its input data to be sorted on the join keys. In
399    this example each input is sorted by using an index scan to visit the
400    rows in the correct order; but a sequential scan and sort could also be
401    used. (Sequential-scan-and-sort frequently beats an index scan for
402    sorting many rows, because of the nonsequential disk access required by
403    the index scan.)
404
405    One way to look at variant plans is to force the planner to disregard
406    whatever strategy it thought was the cheapest, using the enable/disable
407    flags described in Section 19.7.1. (This is a crude tool, but useful.
408    See also Section 14.3.) For example, if we're unconvinced that merge
409    join is the best join type for the previous example, we could try
410 SET enable_mergejoin = off;
411
412 EXPLAIN SELECT *
413 FROM tenk1 t1, onek t2
414 WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2;
415
416                                         QUERY PLAN
417 -------------------------------------------------------------------​------------
418 -----------
419  Hash Join  (cost=226.23..344.08 rows=10 width=488)
420    Hash Cond: (t2.unique2 = t1.unique2)
421    ->  Seq Scan on onek t2  (cost=0.00..114.00 rows=1000 width=244)
422    ->  Hash  (cost=224.98..224.98 rows=100 width=244)
423          ->  Bitmap Heap Scan on tenk1 t1  (cost=5.06..224.98 rows=100 width=244
424 )
425                Recheck Cond: (unique1 < 100)
426                ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100
427  width=0)
428                      Index Cond: (unique1 < 100)
429
430    which shows that the planner thinks that hash join would be nearly 50%
431    more expensive than merge join for this case. Of course, the next
432    question is whether it's right about that. We can investigate that
433    using EXPLAIN ANALYZE, as discussed below.
434
435    When using the enable/disable flags to disable plan node types, many of
436    the flags only discourage the use of the corresponding plan node and
437    don't outright disallow the planner's ability to use the plan node
438    type. This is by design so that the planner still maintains the ability
439    to form a plan for a given query. When the resulting plan contains a
440    disabled node, the EXPLAIN output will indicate this fact.
441 SET enable_seqscan = off;
442 EXPLAIN SELECT * FROM unit;
443
444                        QUERY PLAN
445 ---------------------------------------------------------
446  Seq Scan on unit  (cost=0.00..21.30 rows=1130 width=44)
447    Disabled: true
448
449    Because the unit table has no indexes, there is no other means to read
450    the table data, so the sequential scan is the only option available to
451    the query planner.
452
453    Some query plans involve subplans, which arise from sub-SELECTs in the
454    original query. Such queries can sometimes be transformed into ordinary
455    join plans, but when they cannot be, we get plans like:
456 EXPLAIN VERBOSE SELECT unique1
457 FROM tenk1 t
458 WHERE t.ten < ALL (SELECT o.ten FROM onek o WHERE o.four = t.four);
459
460                                QUERY PLAN
461 -------------------------------------------------------------------​------
462  Seq Scan on public.tenk1 t  (cost=0.00..586095.00 rows=5000 width=4)
463    Output: t.unique1
464    Filter: (ALL (t.ten < (SubPlan 1).col1))
465    SubPlan 1
466      ->  Seq Scan on public.onek o  (cost=0.00..116.50 rows=250 width=4)
467            Output: o.ten
468            Filter: (o.four = t.four)
469
470    This rather artificial example serves to illustrate a couple of points:
471    values from the outer plan level can be passed down into a subplan
472    (here, t.four is passed down) and the results of the sub-select are
473    available to the outer plan. Those result values are shown by EXPLAIN
474    with notations like (subplan_name).colN, which refers to the N'th
475    output column of the sub-SELECT.
476
477    In the example above, the ALL operator runs the subplan again for each
478    row of the outer query (which accounts for the high estimated cost).
479    Some queries can use a hashed subplan to avoid that:
480 EXPLAIN SELECT *
481 FROM tenk1 t
482 WHERE t.unique1 NOT IN (SELECT o.unique1 FROM onek o);
483
484                                          QUERY PLAN
485 -------------------------------------------------------------------​------------
486 -------------
487  Seq Scan on tenk1 t  (cost=61.77..531.77 rows=5000 width=244)
488    Filter: (NOT (ANY (unique1 = (hashed SubPlan 1).col1)))
489    SubPlan 1
490      ->  Index Only Scan using onek_unique1 on onek o  (cost=0.28..59.27 rows=10
491 00 width=4)
492 (4 rows)
493
494    Here, the subplan is run a single time and its output is loaded into an
495    in-memory hash table, which is then probed by the outer ANY operator.
496    This requires that the sub-SELECT not reference any variables of the
497    outer query, and that the ANY's comparison operator be amenable to
498    hashing.
499
500    If, in addition to not referencing any variables of the outer query,
501    the sub-SELECT cannot return more than one row, it may instead be
502    implemented as an initplan:
503 EXPLAIN VERBOSE SELECT unique1
504 FROM tenk1 t1 WHERE t1.ten = (SELECT (random() * 10)::integer);
505
506                              QUERY PLAN
507 ------------------------------------------------------------​--------
508  Seq Scan on public.tenk1 t1  (cost=0.02..470.02 rows=1000 width=4)
509    Output: t1.unique1
510    Filter: (t1.ten = (InitPlan 1).col1)
511    InitPlan 1
512      ->  Result  (cost=0.00..0.02 rows=1 width=4)
513            Output: ((random() * '10'::double precision))::integer
514
515    An initplan is run only once per execution of the outer plan, and its
516    results are saved for re-use in later rows of the outer plan. So in
517    this example random() is evaluated only once and all the values of
518    t1.ten are compared to the same randomly-chosen integer. That's quite
519    different from what would happen without the sub-SELECT construct.
520
521 14.1.2. EXPLAIN ANALYZE #
522
523    It is possible to check the accuracy of the planner's estimates by
524    using EXPLAIN's ANALYZE option. With this option, EXPLAIN actually
525    executes the query, and then displays the true row counts and true run
526    time accumulated within each plan node, along with the same estimates
527    that a plain EXPLAIN shows. For example, we might get a result like
528    this:
529 EXPLAIN ANALYZE SELECT *
530 FROM tenk1 t1, tenk2 t2
531 WHERE t1.unique1 < 10 AND t1.unique2 = t2.unique2;
532
533                                                            QUERY PLAN
534 -------------------------------------------------------------------​------------
535 --------------------------------------------------
536  Nested Loop  (cost=4.65..118.50 rows=10 width=488) (actual time=0.017..0.051 ro
537 ws=10.00 loops=1)
538    Buffers: shared hit=36 read=6
539    ->  Bitmap Heap Scan on tenk1 t1  (cost=4.36..39.38 rows=10 width=244) (actua
540 l time=0.009..0.017 rows=10.00 loops=1)
541          Recheck Cond: (unique1 < 10)
542          Heap Blocks: exact=10
543          Buffers: shared hit=3 read=5 written=4
544          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..4.36 rows=10 width=
545 0) (actual time=0.004..0.004 rows=10.00 loops=1)
546                Index Cond: (unique1 < 10)
547                Index Searches: 1
548                Buffers: shared hit=2
549    ->  Index Scan using tenk2_unique2 on tenk2 t2  (cost=0.29..7.90 rows=1 width
550 =244) (actual time=0.003..0.003 rows=1.00 loops=10)
551          Index Cond: (unique2 = t1.unique2)
552          Index Searches: 10
553          Buffers: shared hit=24 read=6
554  Planning:
555    Buffers: shared hit=15 dirtied=9
556  Planning Time: 0.485 ms
557  Execution Time: 0.073 ms
558
559    Note that the “actual time” values are in milliseconds of real time,
560    whereas the cost estimates are expressed in arbitrary units; so they
561    are unlikely to match up. The thing that's usually most important to
562    look for is whether the estimated row counts are reasonably close to
563    reality. In this example the estimates were all dead-on, but that's
564    quite unusual in practice.
565
566    In some query plans, it is possible for a subplan node to be executed
567    more than once. For example, the inner index scan will be executed once
568    per outer row in the above nested-loop plan. In such cases, the loops
569    value reports the total number of executions of the node, and the
570    actual time and rows values shown are averages per-execution. This is
571    done to make the numbers comparable with the way that the cost
572    estimates are shown. Multiply by the loops value to get the total time
573    actually spent in the node. In the above example, we spent a total of
574    0.030 milliseconds executing the index scans on tenk2.
575
576    In some cases EXPLAIN ANALYZE shows additional execution statistics
577    beyond the plan node execution times and row counts. For example, Sort
578    and Hash nodes provide extra information:
579 EXPLAIN ANALYZE SELECT *
580 FROM tenk1 t1, tenk2 t2
581 WHERE t1.unique1 < 100 AND t1.unique2 = t2.unique2 ORDER BY t1.fivethous;
582
583                                                                  QUERY PLAN
584 -------------------------------------------------------------------​------------
585 -------------------------------------------------------​------
586  Sort  (cost=713.05..713.30 rows=100 width=488) (actual time=2.995..3.002 rows=1
587 00.00 loops=1)
588    Sort Key: t1.fivethous
589    Sort Method: quicksort  Memory: 74kB
590    Buffers: shared hit=440
591    ->  Hash Join  (cost=226.23..709.73 rows=100 width=488) (actual time=0.515..2
592 .920 rows=100.00 loops=1)
593          Hash Cond: (t2.unique2 = t1.unique2)
594          Buffers: shared hit=437
595          ->  Seq Scan on tenk2 t2  (cost=0.00..445.00 rows=10000 width=244) (act
596 ual time=0.026..1.790 rows=10000.00 loops=1)
597                Buffers: shared hit=345
598          ->  Hash  (cost=224.98..224.98 rows=100 width=244) (actual time=0.476..
599 0.477 rows=100.00 loops=1)
600                Buckets: 1024  Batches: 1  Memory Usage: 35kB
601                Buffers: shared hit=92
602                ->  Bitmap Heap Scan on tenk1 t1  (cost=5.06..224.98 rows=100 wid
603 th=244) (actual time=0.030..0.450 rows=100.00 loops=1)
604                      Recheck Cond: (unique1 < 100)
605                      Heap Blocks: exact=90
606                      Buffers: shared hit=92
607                      ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 ro
608 ws=100 width=0) (actual time=0.013..0.013 rows=100.00 loops=1)
609                            Index Cond: (unique1 < 100)
610                            Index Searches: 1
611                            Buffers: shared hit=2
612  Planning:
613    Buffers: shared hit=12
614  Planning Time: 0.187 ms
615  Execution Time: 3.036 ms
616
617    The Sort node shows the sort method used (in particular, whether the
618    sort was in-memory or on-disk) and the amount of memory or disk space
619    needed. The Hash node shows the number of hash buckets and batches as
620    well as the peak amount of memory used for the hash table. (If the
621    number of batches exceeds one, there will also be disk space usage
622    involved, but that is not shown.)
623
624    Index Scan nodes (as well as Bitmap Index Scan and Index-Only Scan
625    nodes) show an “Index Searches” line that reports the total number of
626    searches across all node executions/loops:
627 EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE thousand IN (1, 500, 700, 999);
628                                                             QUERY PLAN
629 -------------------------------------------------------------------​------------
630 ---------------------------------------------------
631  Bitmap Heap Scan on tenk1  (cost=9.45..73.44 rows=40 width=244) (actual time=0.
632 012..0.028 rows=40.00 loops=1)
633    Recheck Cond: (thousand = ANY ('{1,500,700,999}'::integer[]))
634    Heap Blocks: exact=39
635    Buffers: shared hit=47
636    ->  Bitmap Index Scan on tenk1_thous_tenthous  (cost=0.00..9.44 rows=40 width
637 =0) (actual time=0.009..0.009 rows=40.00 loops=1)
638          Index Cond: (thousand = ANY ('{1,500,700,999}'::integer[]))
639          Index Searches: 4
640          Buffers: shared hit=8
641  Planning Time: 0.029 ms
642  Execution Time: 0.034 ms
643
644    Here we see a Bitmap Index Scan node that needed 4 separate index
645    searches. The scan had to search the index from the
646    tenk1_thous_tenthous index root page once per integer value from the
647    predicate's IN construct. However, the number of index searches often
648    won't have such a simple correspondence to the query predicate:
649 EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE thousand IN (1, 2, 3, 4);
650                                                             QUERY PLAN
651 -------------------------------------------------------------------​------------
652 ---------------------------------------------------
653  Bitmap Heap Scan on tenk1  (cost=9.45..73.44 rows=40 width=244) (actual time=0.
654 009..0.019 rows=40.00 loops=1)
655    Recheck Cond: (thousand = ANY ('{1,2,3,4}'::integer[]))
656    Heap Blocks: exact=38
657    Buffers: shared hit=40
658    ->  Bitmap Index Scan on tenk1_thous_tenthous  (cost=0.00..9.44 rows=40 width
659 =0) (actual time=0.005..0.005 rows=40.00 loops=1)
660          Index Cond: (thousand = ANY ('{1,2,3,4}'::integer[]))
661          Index Searches: 1
662          Buffers: shared hit=2
663  Planning Time: 0.029 ms
664  Execution Time: 0.026 ms
665
666    This variant of our IN query performed only 1 index search. It spent
667    less time traversing the index (compared to the original query) because
668    its IN construct uses values matching index tuples stored next to each
669    other, on the same tenk1_thous_tenthous index leaf page.
670
671    The “Index Searches” line is also useful with B-tree index scans that
672    apply the skip scan optimization to more efficiently traverse through
673    an index:
674 EXPLAIN ANALYZE SELECT four, unique1 FROM tenk1 WHERE four BETWEEN 1 AND 3 AND u
675 nique1 = 42;
676                                                               QUERY PLAN
677 -------------------------------------------------------------------​------------
678 ---------------------------------------------------
679  Index Only Scan using tenk1_four_unique1_idx on tenk1  (cost=0.29..6.90 rows=1
680 width=8) (actual time=0.006..0.007 rows=1.00 loops=1)
681    Index Cond: ((four >= 1) AND (four <= 3) AND (unique1 = 42))
682    Heap Fetches: 0
683    Index Searches: 3
684    Buffers: shared hit=7
685  Planning Time: 0.029 ms
686  Execution Time: 0.012 ms
687
688    Here we see an Index-Only Scan node using tenk1_four_unique1_idx, a
689    multi-column index on the tenk1 table's four and unique1 columns. The
690    scan performs 3 searches that each read a single index leaf page: “four
691    = 1 AND unique1 = 42”, “four = 2 AND unique1 = 42”, and “four = 3 AND
692    unique1 = 42”. This index is generally a good target for skip scan,
693    since, as discussed in Section 11.3, its leading column (the four
694    column) contains only 4 distinct values, while its second/final column
695    (the unique1 column) contains many distinct values.
696
697    Another type of extra information is the number of rows removed by a
698    filter condition:
699 EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE ten < 7;
700
701                                                QUERY PLAN
702 -------------------------------------------------------------------​------------
703 --------------------------
704  Seq Scan on tenk1  (cost=0.00..470.00 rows=7000 width=244) (actual time=0.030..
705 1.995 rows=7000.00 loops=1)
706    Filter: (ten < 7)
707    Rows Removed by Filter: 3000
708    Buffers: shared hit=345
709  Planning Time: 0.102 ms
710  Execution Time: 2.145 ms
711
712    These counts can be particularly valuable for filter conditions applied
713    at join nodes. The “Rows Removed” line only appears when at least one
714    scanned row, or potential join pair in the case of a join node, is
715    rejected by the filter condition.
716
717    A case similar to filter conditions occurs with “lossy” index scans.
718    For example, consider this search for polygons containing a specific
719    point:
720 EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
721
722                                               QUERY PLAN
723 -------------------------------------------------------------------​------------
724 -----------------------
725  Seq Scan on polygon_tbl  (cost=0.00..1.09 rows=1 width=85) (actual time=0.023..
726 0.023 rows=0.00 loops=1)
727    Filter: (f1 @> '((0.5,2))'::polygon)
728    Rows Removed by Filter: 7
729    Buffers: shared hit=1
730  Planning Time: 0.039 ms
731  Execution Time: 0.033 ms
732
733    The planner thinks (quite correctly) that this sample table is too
734    small to bother with an index scan, so we have a plain sequential scan
735    in which all the rows got rejected by the filter condition. But if we
736    force an index scan to be used, we see:
737 SET enable_seqscan TO off;
738
739 EXPLAIN ANALYZE SELECT * FROM polygon_tbl WHERE f1 @> polygon '(0.5,2.0)';
740
741                                                         QUERY PLAN
742 -------------------------------------------------------------------​------------
743 -------------------------------------------
744  Index Scan using gpolygonind on polygon_tbl  (cost=0.13..8.15 rows=1 width=85)
745 (actual time=0.074..0.074 rows=0.00 loops=1)
746    Index Cond: (f1 @> '((0.5,2))'::polygon)
747    Rows Removed by Index Recheck: 1
748    Index Searches: 1
749    Buffers: shared hit=1
750  Planning Time: 0.039 ms
751  Execution Time: 0.098 ms
752
753    Here we can see that the index returned one candidate row, which was
754    then rejected by a recheck of the index condition. This happens because
755    a GiST index is “lossy” for polygon containment tests: it actually
756    returns the rows with polygons that overlap the target, and then we
757    have to do the exact containment test on those rows.
758
759    EXPLAIN has a BUFFERS option which provides additional detail about I/O
760    operations performed during the planning and execution of the given
761    query. The buffer numbers displayed show the count of the non-distinct
762    buffers hit, read, dirtied, and written for the given node and all of
763    its child nodes. The ANALYZE option implicitly enables the BUFFERS
764    option. If this is undesired, BUFFERS may be explicitly disabled:
765 EXPLAIN (ANALYZE, BUFFERS OFF) SELECT * FROM tenk1 WHERE unique1 < 100 AND uniqu
766 e2 > 9000;
767
768                                                            QUERY PLAN
769 -------------------------------------------------------------------​------------
770 --------------------------------------------------
771  Bitmap Heap Scan on tenk1  (cost=25.07..60.11 rows=10 width=244) (actual time=0
772 .105..0.114 rows=10.00 loops=1)
773    Recheck Cond: ((unique1 < 100) AND (unique2 > 9000))
774    Heap Blocks: exact=10
775    ->  BitmapAnd  (cost=25.07..25.07 rows=10 width=0) (actual time=0.100..0.101
776 rows=0.00 loops=1)
777          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100 width
778 =0) (actual time=0.027..0.027 rows=100.00 loops=1)
779                Index Cond: (unique1 < 100)
780                Index Searches: 1
781          ->  Bitmap Index Scan on tenk1_unique2  (cost=0.00..19.78 rows=999 widt
782 h=0) (actual time=0.070..0.070 rows=999.00 loops=1)
783                Index Cond: (unique2 > 9000)
784                Index Searches: 1
785  Planning Time: 0.162 ms
786  Execution Time: 0.143 ms
787
788    Keep in mind that because EXPLAIN ANALYZE actually runs the query, any
789    side-effects will happen as usual, even though whatever results the
790    query might output are discarded in favor of printing the EXPLAIN data.
791    If you want to analyze a data-modifying query without changing your
792    tables, you can roll the command back afterwards, for example:
793 BEGIN;
794
795 EXPLAIN ANALYZE UPDATE tenk1 SET hundred = hundred + 1 WHERE unique1 < 100;
796
797                                                            QUERY PLAN
798 -------------------------------------------------------------------​------------
799 -------------------------------------------------
800  Update on tenk1  (cost=5.06..225.23 rows=0 width=0) (actual time=1.634..1.635 r
801 ows=0.00 loops=1)
802    ->  Bitmap Heap Scan on tenk1  (cost=5.06..225.23 rows=100 width=10) (actual
803 time=0.065..0.141 rows=100.00 loops=1)
804          Recheck Cond: (unique1 < 100)
805          Heap Blocks: exact=90
806          Buffers: shared hit=4 read=2
807          ->  Bitmap Index Scan on tenk1_unique1  (cost=0.00..5.04 rows=100 width
808 =0) (actual time=0.031..0.031 rows=100.00 loops=1)
809                Index Cond: (unique1 < 100)
810                Index Searches: 1
811                Buffers: shared read=2
812  Planning Time: 0.151 ms
813  Execution Time: 1.856 ms
814
815 ROLLBACK;
816
817    As seen in this example, when the query is an INSERT, UPDATE, DELETE,
818    or MERGE command, the actual work of applying the table changes is done
819    by a top-level Insert, Update, Delete, or Merge plan node. The plan
820    nodes underneath this node perform the work of locating the old rows
821    and/or computing the new data. So above, we see the same sort of bitmap
822    table scan we've seen already, and its output is fed to an Update node
823    that stores the updated rows. It's worth noting that although the
824    data-modifying node can take a considerable amount of run time (here,
825    it's consuming the lion's share of the time), the planner does not
826    currently add anything to the cost estimates to account for that work.
827    That's because the work to be done is the same for every correct query
828    plan, so it doesn't affect planning decisions.
829
830    When an UPDATE, DELETE, or MERGE command affects a partitioned table or
831    inheritance hierarchy, the output might look like this:
832 EXPLAIN UPDATE gtest_parent SET f1 = CURRENT_DATE WHERE f2 = 101;
833
834                                        QUERY PLAN
835 -------------------------------------------------------------------​------------
836 ---------
837  Update on gtest_parent  (cost=0.00..3.06 rows=0 width=0)
838    Update on gtest_child gtest_parent_1
839    Update on gtest_child2 gtest_parent_2
840    Update on gtest_child3 gtest_parent_3
841    ->  Append  (cost=0.00..3.06 rows=3 width=14)
842          ->  Seq Scan on gtest_child gtest_parent_1  (cost=0.00..1.01 rows=1 wid
843 th=14)
844                Filter: (f2 = 101)
845          ->  Seq Scan on gtest_child2 gtest_parent_2  (cost=0.00..1.01 rows=1 wi
846 dth=14)
847                Filter: (f2 = 101)
848          ->  Seq Scan on gtest_child3 gtest_parent_3  (cost=0.00..1.01 rows=1 wi
849 dth=14)
850                Filter: (f2 = 101)
851
852    In this example the Update node needs to consider three child tables,
853    but not the originally-mentioned partitioned table (since that never
854    stores any data). So there are three input scanning subplans, one per
855    table. For clarity, the Update node is annotated to show the specific
856    target tables that will be updated, in the same order as the
857    corresponding subplans.
858
859    The Planning time shown by EXPLAIN ANALYZE is the time it took to
860    generate the query plan from the parsed query and optimize it. It does
861    not include parsing or rewriting.
862
863    The Execution time shown by EXPLAIN ANALYZE includes executor start-up
864    and shut-down time, as well as the time to run any triggers that are
865    fired, but it does not include parsing, rewriting, or planning time.
866    Time spent executing BEFORE triggers, if any, is included in the time
867    for the related Insert, Update, or Delete node; but time spent
868    executing AFTER triggers is not counted there because AFTER triggers
869    are fired after completion of the whole plan. The total time spent in
870    each trigger (either BEFORE or AFTER) is also shown separately. Note
871    that deferred constraint triggers will not be executed until end of
872    transaction and are thus not considered at all by EXPLAIN ANALYZE.
873
874    The time shown for the top-level node does not include any time needed
875    to convert the query's output data into displayable form or to send it
876    to the client. While EXPLAIN ANALYZE will never send the data to the
877    client, it can be told to convert the query's output data to
878    displayable form and measure the time needed for that, by specifying
879    the SERIALIZE option. That time will be shown separately, and it's also
880    included in the total Execution time.
881
882 14.1.3. Caveats #
883
884    There are two significant ways in which run times measured by EXPLAIN
885    ANALYZE can deviate from normal execution of the same query. First,
886    since no output rows are delivered to the client, network transmission
887    costs are not included. I/O conversion costs are not included either
888    unless SERIALIZE is specified. Second, the measurement overhead added
889    by EXPLAIN ANALYZE can be significant, especially on machines with slow
890    gettimeofday() operating-system calls. You can use the pg_test_timing
891    tool to measure the overhead of timing on your system.
892
893    EXPLAIN results should not be extrapolated to situations much different
894    from the one you are actually testing; for example, results on a
895    toy-sized table cannot be assumed to apply to large tables. The
896    planner's cost estimates are not linear and so it might choose a
897    different plan for a larger or smaller table. An extreme example is
898    that on a table that only occupies one disk page, you'll nearly always
899    get a sequential scan plan whether indexes are available or not. The
900    planner realizes that it's going to take one disk page read to process
901    the table in any case, so there's no value in expending additional page
902    reads to look at an index. (We saw this happening in the polygon_tbl
903    example above.)
904
905    There are cases in which the actual and estimated values won't match up
906    well, but nothing is really wrong. One such case occurs when plan node
907    execution is stopped short by a LIMIT or similar effect. For example,
908    in the LIMIT query we used before,
909 EXPLAIN ANALYZE SELECT * FROM tenk1 WHERE unique1 < 100 AND unique2 > 9000 LIMIT
910  2;
911
912                                                           QUERY PLAN
913 -------------------------------------------------------------------​------------
914 ------------------------------------------------
915  Limit  (cost=0.29..14.33 rows=2 width=244) (actual time=0.051..0.071 rows=2.00
916 loops=1)
917    Buffers: shared hit=16
918    ->  Index Scan using tenk1_unique2 on tenk1  (cost=0.29..70.50 rows=10 width=
919 244) (actual time=0.051..0.070 rows=2.00 loops=1)
920          Index Cond: (unique2 > 9000)
921          Filter: (unique1 < 100)
922          Rows Removed by Filter: 287
923          Index Searches: 1
924          Buffers: shared hit=16
925  Planning Time: 0.077 ms
926  Execution Time: 0.086 ms
927
928    the estimated cost and row count for the Index Scan node are shown as
929    though it were run to completion. But in reality the Limit node stopped
930    requesting rows after it got two, so the actual row count is only 2 and
931    the run time is less than the cost estimate would suggest. This is not
932    an estimation error, only a discrepancy in the way the estimates and
933    true values are displayed.
934
935    Merge joins also have measurement artifacts that can confuse the
936    unwary. A merge join will stop reading one input if it's exhausted the
937    other input and the next key value in the one input is greater than the
938    last key value of the other input; in such a case there can be no more
939    matches and so no need to scan the rest of the first input. This
940    results in not reading all of one child, with results like those
941    mentioned for LIMIT. Also, if the outer (first) child contains rows
942    with duplicate key values, the inner (second) child is backed up and
943    rescanned for the portion of its rows matching that key value. EXPLAIN
944    ANALYZE counts these repeated emissions of the same inner rows as if
945    they were real additional rows. When there are many outer duplicates,
946    the reported actual row count for the inner child plan node can be
947    significantly larger than the number of rows that are actually in the
948    inner relation.
949
950    BitmapAnd and BitmapOr nodes always report their actual row counts as
951    zero, due to implementation limitations.
952
953    Normally, EXPLAIN will display every plan node created by the planner.
954    However, there are cases where the executor can determine that certain
955    nodes need not be executed because they cannot produce any rows, based
956    on parameter values that were not available at planning time.
957    (Currently this can only happen for child nodes of an Append or
958    MergeAppend node that is scanning a partitioned table.) When this
959    happens, those plan nodes are omitted from the EXPLAIN output and a
960    Subplans Removed: N annotation appears instead.