EXPLAIN SETTINGS, WAL and SERIALIZE Options #

Three symptoms that plain EXPLAIN ANALYZE cannot explain: the plan on staging differs from production even though the data matches; a small batch UPDATE saturates the replication link at some times of day and not others; and a query the server clocks at 120 ms takes 700 ms in the application. Each has an option that adds exactly the missing evidence.

All the options are introduced in EXPLAIN options and output formats. This page shows how to read these three and act on what they say.

The Conditions Each Option Exposes #

SETTINGS (PostgreSQL 12+) prints every planner-relevant parameter whose value differs from the compiled-in default. Plans are a function of statistics, data, and configuration; this line captures configuration. It includes values from postgresql.conf, ALTER DATABASE, ALTER ROLE, the connection string, and SET.

WAL (PostgreSQL 13+, requires ANALYZE) reports WAL generated by each node: records, fpi (full-page images) and bytes. A full-page image is written the first time a page is modified after each checkpoint, so the same statement can produce very different WAL volumes depending on when it runs.

SERIALIZE (PostgreSQL 17+, requires ANALYZE) makes the server convert every result row to its wire format — text or binary — which includes detoasting compressed or out-of-line values, then discards the output. It reports the time and bytes. Without it, EXPLAIN ANALYZE never detoasts columns that are only returned, never filtered, so a query returning large jsonb documents looks much cheaper than it is.

What each option makes visible Three columns. SETTINGS reveals configuration that differs between environments, shown as a Settings line listing work_mem and random_page_cost. WAL reveals write amplification, shown as a WAL line with records, full-page images and bytes. SERIALIZE reveals output conversion cost, shown as a Serialization line with time and output size. SETTINGS hidden: configuration work_mem = '256MB' random_page_cost = '1.1' why plans differ WAL hidden: write volume records=50012 fpi=18240 bytes=151208812 why replication lags SERIALIZE hidden: output cost time=486.2 ms output=212044kB why clients wait

Annotated EXPLAIN Evidence #

SETTINGS — staging vs production:

-- production
Settings: effective_cache_size = '48GB', random_page_cost = '1.1', work_mem = '64MB'
-- staging
Settings: work_mem = '64MB'
-- staging runs random_page_cost = 4 (default) and effective_cache_size = 4GB (default):
-- index scans look ~3.6× more expensive there, so the same query picks a seq scan

The difference is fully explained by two missing lines, which is the tuning random_page_cost for SSD storage problem in reverse.

WAL — the same update at two moments:

BEGIN;
EXPLAIN (ANALYZE, WAL)
UPDATE sessions SET last_seen = now()
WHERE id IN (SELECT session_id FROM heartbeat_batch);   -- 50,000 ids
ROLLBACK;
-- 10 seconds after a checkpoint
Update on sessions  (actual time=912.4..912.4 rows=0 loops=1)
  WAL: records=100024 fpi=18240 bytes=151208812        -- 144 MB, mostly full-page images
-- 4 minutes into the checkpoint cycle
Update on sessions  (actual time=388.1..388.1 rows=0 loops=1)
  WAL: records=100024 fpi=0 bytes=11402736             -- 11 MB
-- records identical; fpi decides the volume

SERIALIZE — the invisible 486 ms:

EXPLAIN (ANALYZE, SERIALIZE)
SELECT id, document FROM contracts WHERE customer_id = 8812;
Index Scan using contracts_customer_idx on contracts  (actual time=0.04..118.6 rows=4210 loops=1)
Planning Time: 0.2 ms
Serialization: time=486.2 ms  output=212044kB  format=text
Execution Time: 605.1 ms
-- without SERIALIZE: Execution Time ≈ 119 ms, because document (large jsonb) was never detoasted
-- 212 MB of output is also what the network and client must handle
One line per option Three output lines are annotated. The Settings line lists non-default planner parameters. The WAL line with full-page images shows write amplification. The Serialization line shows output conversion time and size. Settings: random_page_cost = '1.1' planner inputs that differ WAL: records=100024 fpi=18240 full-page images drive volume Serialization: time=486.2 ms output cost hidden without it

Step-by-Step Resolution #

  1. Diff configuration first. Capture EXPLAIN (SETTINGS) on both environments for the same statement and compare the Settings: lines. Then find where each value comes from:

    SELECT name, setting, source, sourcefile
FROM pg_settings WHERE name IN ('random_page_cost', 'effective_cache_size', 'work_mem');

    The layers that can set a value are covered in session parameter drift.

  2. Measure writes with WAL in a rolled-back transaction, and repeat at different points relative to checkpoints:

    SELECT now() - checkpoint_time AS since_checkpoint FROM pg_control_checkpoint();

  3. Reduce full-page-image amplification when it dominates. Options include spreading large batches over time, increasing checkpoint_timeout and max_wal_size so checkpoints are less frequent, and enabling wal_compression. Each has trade-offs in recovery time and CPU.

  4. Add SERIALIZE to any read returning wide values — jsonb, text, bytea, arrays — or many rows. If serialization rivals execution, the fix is in the select list: return only needed columns, or fetch large documents separately.

    EXPLAIN (ANALYZE, SERIALIZE)
SELECT id, document -> 'summary' AS summary FROM contracts WHERE customer_id = 8812;
-- Serialization: time=31.4 ms  output=8240kB

  5. Attribute what is left. Application latency minus Execution Time (with SERIALIZE) is network, driver decoding and application work.

Full-page images decide WAL volume Two stacked bars for the same update. Right after a checkpoint the bar is 144 megabytes, of which about 133 megabytes are full-page images and 11 megabytes are ordinary records. Four minutes later the bar is 11 megabytes of ordinary records only. 10 s after checkpoint full-page images ≈ 133 MB 4 min later records ≈ 11 MB, fpi = 0 identical statement, identical record count — a 13× difference in bytes shipped to replicas

Before and After #

-- BEFORE: EXPLAIN ANALYZE (no SERIALIZE), app sees 700 ms
Execution Time: 119.4 ms

-- AFTER: EXPLAIN (ANALYZE, SERIALIZE), select list narrowed to document -> 'summary'
Serialization: time=31.4 ms  output=8240kB
Execution Time: 151.8 ms          -- app now sees ~190 ms

Why detoasting hides from plain ANALYZE #

Values larger than about 2 kB are compressed and, if still large, moved out of line into the table’s TOAST relation, leaving a pointer in the main row. The executor passes that pointer upward through scans, joins and sorts without expanding it unless a node needs the actual content — a filter, a sort key, or a function call on the column. Returning the column to the client is the moment the value must be fetched and decompressed. Plain EXPLAIN ANALYZE discards result rows before that point, so the fetch and decompression never happen and never appear in any node’s time or buffers. SERIALIZE performs the output conversion, which forces detoasting, and so the TOAST reads and decompression finally become visible — including in the Buffers totals when BUFFERS is also requested.

This is why a query returning jsonb documents can look fast in every plan and still dominate latency. The index scan found 4,210 rows cheaply; converting 212 MB of documents to text was the actual work.

Reading SETTINGS when the difference is not a planner setting #

SETTINGS lists only parameters that influence planning. Execution-only parameters — statement_timeout, lock_timeout, temp_buffers in some versions, logging settings — do not appear, and neither does anything outside PostgreSQL’s configuration: different hardware, a different number of CPUs available for parallel workers, or different cache warmth. When two environments show identical Settings: lines and still produce different plans, move on to statistics (pg_stats on the columns involved), table and index sizes (pg_class.relpages), and server version. When they produce identical plans with different timings, compare Buffers read counts: a cold cache in one environment is far more common than a configuration difference.

WAL numbers have a similar boundary. They count WAL generated by the statement’s own nodes, not WAL generated by triggers’ side effects in other tables when those are executed outside the plan tree, and not WAL from index maintenance work deferred to vacuum. Treat them as a lower bound on what the statement causes to be replicated.

Common Pitfalls #

Reading an empty Settings: as “no differences”. The line lists differences from compiled defaults, not from another server. Diagnostic signal: no Settings: line on either side, yet plans differ. Fix: compare statistics and data size next; configuration is ruled out.

Using WAL without ANALYZE. WAL is only generated by execution. Diagnostic signal: an error that WAL requires ANALYZE. Fix: run inside BEGIN … ROLLBACK.

Blaming the query for serialization. A fast plan returning huge documents is an application design problem, not a planner one. Diagnostic signal: tiny node times with a large Serialization: line. Fix: narrow the select list or paginate large values.

Assuming SERIALIZE includes the network. It stops at conversion. Diagnostic signal: remaining latency after accounting for serialization. Fix: measure client-side round trips and driver decoding separately.

Frequently Asked Questions #

Which parameters does EXPLAIN SETTINGS show? Planner-relevant parameters whose value differs from the compiled default — work_mem, random_page_cost, effective_cache_size, the enable_* switches, join_collapse_limit, plan_cache_mode and similar. Values from postgresql.conf count as non-default.

What is fpi in the WAL line of EXPLAIN? Full-page images: whole-page copies written the first time a page is modified after a checkpoint. They make the same write far heavier early in a checkpoint cycle.

Does SERIALIZE send the rows to my client? No. It converts rows to wire format, detoasting large values, and discards the bytes. Network and client time must be measured separately.

Up: EXPLAIN Options and Output Formats