EXPLAIN's Other Superpowers
Introduction
Most people who work with PostgreSQL eventually learn two commands for query tuning: EXPLAIN and EXPLAIN ANALYZE.
EXPLAIN shows the planner’s chosen execution plan, and EXPLAIN ANALYZE runs the query and adds runtime statistics. For most tuning tasks, this already provides a wealth of information.
But what many people don’t realize is that EXPLAIN has a handful of other options that can make troubleshooting much easier. In some cases they answer questions that EXPLAIN ANALYZE alone cannot.
In this post we’ll take a look at a few of those lesser-known options.
BUFFERS: Where Did the Data Come From?
One common question during performance analysis is whether data came from: shared buffers (cache), disk, or temporary buffers. This is where the BUFFERS option comes in handy. Output can look something like this:
EXPLAIN (ANALYZE, BUFFERS)
SELECT * FROM mytable WHERE id = 123;
[...]
Index Scan using mytable_pkey on mytable
Buffers: shared hit=5 read=2
[...]
In the example above, we see:
shared hit– pages already in cache (i.e., cache hit)shared read– pages fetched from disk (i.e., cache miss)
Note that buffers in this context are 8 kilobyte blocks of memory (standard block size for most storage systems)
This is extremely useful when trying to determine if performance problems are related to: cold cache, excessive disk reads, or insufficient memory (i.e., cache is too crowded to keep all the data being worked with).
Especially for index scans, this information confirms whether a query that should be index-friendly is actually pulling large portions of the table into memory.
MEMORY: Memory used by the
This is a new feature introduced in version 18. It is different from BUFFERS in the sense that it tracks the amount of memory consumed during the query planning phase, not execution. Output would appear at the bottom of EXPLAIN output like this:
EXPLAIN (ANALYZE, TIMING OFF)
SELECT * FROM mytable WHERE id = 123;
[...]
Planning:
Buffers: shared hit=36 read=1
Memory: used=63kB allocated=64kB
WAL: How Much Logging Is Happening?
Another useful option that many people overlook is WAL:
EXPLAIN (ANALYZE, WAL)
INSERT INTO mytable SELECT * FROM staging_table;
[...]
WAL: records=100, fpi=5, bytes=45000
In the example above, records are the number of WAL records generated, fpi refers to full-page images that were written (number of pages modified for the first time since the last checkpoint), and bytes is the total WAL traffic generated by the query. This can be helpful when investigating write-heavy workloads, including bulk loads, large updates, index creation, and high replication traffic.
SETTINGS: Remind me what my environment looked like?
Sometimes a query behaves differently on two servers even though the SQL is identical. Or you may have modified some parameters locally before running the query (i.e., work_mem). To properly understand how a query is affected by any differences in environment, the SETTINGS option can sometimes be useful:
EXPLAIN (SETTINGS)
SELECT * FROM mytable WHERE id = 123;
[...]
Settings: effective_cache_size = '48GB', effective_io_concurrency = '200', enable_partitionwise_aggregate = 'on', enable_partitionwise_join = 'on', max_parallel_workers = '16', max_parallel_workers_per_gather = '4', temp_buffers = '1MB', search_path = 'public'
VERBOSE: See the Planner’s Full Story
Another useful option is VERBOSE, which prints additional information like, internal column references, expanded target lists, and schema-qualified objects:
postgres=# EXPLAIN (ANALYZE) SELECT * FROM pgbench_accounts a JOIN pgbench_branches b ON b.bid=a.bid ORDER BY 2 DESC;
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=0.12..3898.14 rows=100000 width=461) (actual time=0.216..32.597 rows=100000.00 loops=1)
Join Filter: (b.bid = a.bid)
Buffers: shared hit=1642
-> Index Scan Backward using pgbench_branches_pkey on pgbench_branches b (cost=0.12..8.14 rows=1 width=364) (actual time=0.095..0.102 rows=1.00 loops=1)
Index Searches: 1
Buffers: shared hit=2
-> Seq Scan on pgbench_accounts a (cost=0.00..2640.00 rows=100000 width=97) (actual time=0.024..9.732 rows=100000.00 loops=1)
Buffers: shared hit=1640
Planning Time: 0.346 ms
Execution Time: 40.078 ms
(10 rows)
postgres=# EXPLAIN (ANALYZE, VERBOSE) SELECT * FROM pgbench_accounts a JOIN pgbench_branches b ON b.bid=a.bid ORDER BY 2 DESC;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=0.12..3898.14 rows=100000 width=461) (actual time=0.225..32.869 rows=100000.00 loops=1)
Output: a.aid, a.bid, a.abalance, a.filler, b.bid, b.bbalance, b.filler
Join Filter: (b.bid = a.bid)
Buffers: shared hit=1642
-> Index Scan Backward using pgbench_branches_pkey on public.pgbench_branches b (cost=0.12..8.14 rows=1 width=364) (actual time=0.183..0.190 rows=1.00 loops=1)
Output: b.bid, b.bbalance, b.filler
Index Searches: 1
Buffers: shared hit=2
-> Seq Scan on public.pgbench_accounts a (cost=0.00..2640.00 rows=100000 width=97) (actual time=0.026..9.756 rows=100000.00 loops=1)
Output: a.aid, a.bid, a.abalance, a.filler
Buffers: shared hit=1640
Planning Time: 0.547 ms
Execution Time: 40.228 ms
(13 rows)
While it may look a bit noisy, it can be helpful when diagnosing:
- view expansion
- rule rewriting
- complex query transformations
Combining Options
The real power of EXPLAIN comes from combining options together. For example:
EXPLAIN (ANALYZE, BUFFERS, WAL, SETTINGS)
SELECT * FROM mytable WHERE id = 123;
This produces a plan that shows execution time, cache usage, WAL generation, and configuration parameters influencing the planner
In many cases, this gives a far more complete picture of what the database is doing internally.
Note that many of these can also be enabled in auto_explain as parameters in the database configuration.
Conclusion
EXPLAIN ANALYZE is powerful, but the feature provides many additional tools for understanding query behavior. These additional options can provide valuable insight into memory usage, disk activity, WAL generation, and instrumentation overhead. When troubleshooting tricky performance problems, these options can reveal details that a basic execution plan might hide.