How much of a vacuum is spent asleep

Two vacuums that look identical from outside

An autovacuum has been running on your largest table for three hours. That sentence describes two completely different situations, and until PostgreSQL 18 the server gave you no way to tell which one you had.

In the first, the table genuinely has three hours of work in it. There are that many dead rows, that many index entries to clean, that much of the heap to scan. The vacuum is working continuously and the answer is either to let it finish or to give it more memory so it needs fewer passes.

In the second, the table has twenty minutes of work in it and the vacuum is asleep for most of every second. The cost-based delay is a deliberate throttle: after a certain amount of accumulated work, vacuum stops and waits, so that maintenance does not saturate the storage a production workload is trying to use. When that throttle is set too tight for the amount of churn a table is taking, vacuum falls permanently behind while using almost no resources at all, and every instinct about a long-running process points at exactly the wrong remedy.

The two are distinguishable in principle by watching the progress view move slowly and inferring the rest. Version 18 stops the inferring. Both progress views gained a column reporting the accumulated time spent asleep under the delay, and the same figure goes into the log line when the vacuum ends.

Neither exists on 17.

SHOW track_cost_delay_timing;

ERROR:  unrecognized configuration parameter "track_cost_delay_timing"

SELECT pid, phase, delay_time FROM pg_stat_progress_vacuum;

ERROR:  column "delay_time" does not exist
LINE 1: SELECT pid, phase, delay_time FROM pg_stat_progress_vacuum;
                           ^

The setting is off, and it applies to the wrong session by default

The measurement is gated, which is the right decision and is also the step people miss. The setting is off out of the box.

ALTER SYSTEM SET track_cost_delay_timing = on;
SELECT pg_reload_conf();
SELECT pg_sleep(1);
SHOW track_cost_delay_timing;

ALTER SYSTEM
 pg_reload_conf 
----------------
 t
(1 row)

 pg_sleep 
----------
 
(1 row)

 track_cost_delay_timing 
-------------------------
 on
(1 row)

Setting it for the cluster and reloading is deliberate rather than lazy. The processes whose delay you care about are autovacuum workers, and they are started by the server rather than by you, so a session-level setting reaches nothing that matters. It takes a reload rather than a restart, and it is reversible the same way.

Watching a throttled vacuum from another session

The cluster below has the delay tightened well past anything sensible, so that the effect is unmissable in a fixture that finishes inside a page. The table gets four hundred thousand rows and then every one of them is updated, which leaves a full table’s worth of dead rows for autovacuum to find. The progress view is then sampled twice, three seconds apart.

CREATE TABLE ledger_rows (row_id bigint PRIMARY KEY, body text);
INSERT INTO ledger_rows SELECT g, md5(g::text) FROM generate_series(1, 400000) AS g;
VACUUM ANALYZE ledger_rows;
UPDATE ledger_rows SET body = upper(body);
SELECT pg_sleep(4);
SELECT phase, heap_blks_scanned, heap_blks_total, round(delay_time::numeric, 0) AS delay_ms
FROM pg_stat_progress_vacuum WHERE relid = 'ledger_rows'::regclass;
SELECT pg_sleep(3);
SELECT phase, heap_blks_scanned, round(delay_time::numeric, 0) AS delay_ms
FROM pg_stat_progress_vacuum WHERE relid = 'ledger_rows'::regclass;

CREATE TABLE
INSERT 0 400000
VACUUM
UPDATE 400000
 pg_sleep 
----------
 
(1 row)

     phase     | heap_blks_scanned | heap_blks_total | delay_ms 
---------------+-------------------+-----------------+----------
 scanning heap |              1586 |            7477 |     2385
(1 row)

 pg_sleep 
----------
 
(1 row)

     phase     | heap_blks_scanned | delay_ms 
---------------+-------------------+----------
 scanning heap |              3096 |     4471
(1 row)

Read the two samples together, because a single reading of this column tells you almost nothing and the difference between two tells you everything.

Three seconds of wall clock passed between them. The delay figure went up by two thousand eight hundred and sixty-seven milliseconds. That vacuum spent ninety-six percent of the interval asleep, waiting out a throttle, and about a tenth of a second doing work. It scanned nineteen hundred heap blocks in that time; with the throttle removed it would have scanned them in a moment.

That is the number the release gives you, and the way to use it is as a ratio rather than a total. Two samples, the difference in the delay column over the difference in wall clock, and you have the fraction of the vacuum that is throttle rather than work. Above ninety percent means the delay settings are the entire story. Below about a quarter means they are not, and the table really does have that much work in it, and the answer is memory or fewer index passes rather than a looser throttle.

The progress view for analyze gained the same column, with the same gate, and it matters less often only because analyze is short.

The same figure lands in the log

Sampling a progress view catches vacuums that are running when you look. The log catches all of them, and 18 puts the delay total into the line that autovacuum writes when it finishes, which is the version of this measurement you can collect without a poller.

The block below runs on both servers: a small table, updated in full, left alone until autovacuum has dealt with it, and then the relevant lines pulled out of the log file.

CREATE TABLE audit_batch (batch_id bigint PRIMARY KEY, body text);
INSERT INTO audit_batch SELECT g, md5(g::text) FROM generate_series(1, 20000) AS g;
UPDATE audit_batch SET body = upper(body);
SELECT pg_sleep(40);
SELECT btrim(line) AS logged
FROM regexp_split_to_table(pg_read_file('log/postgresql.log'), E'\n') AS line
WHERE line LIKE '%delay time:%' OR line LIKE '%system usage:%'
LIMIT 3;

On 17 the only thing the log has to say about how long the work took is the resource summary.

CREATE TABLE
INSERT 0 20000
UPDATE 20000
 pg_sleep 
----------
 
(1 row)

                                  logged                                  
--------------------------------------------------------------------------
         system usage: CPU: user: 0.02 s, system: 0.01 s, elapsed: 0.34 s
         system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.10 s
         system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.11 s
(3 rows)

On 18, with the setting on, a new line joins them.

CREATE TABLE
INSERT 0 20000
UPDATE 20000
 pg_sleep 
----------
 
(1 row)

                                  logged                                  
--------------------------------------------------------------------------
         system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.13 s
         system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.14 s
         delay time: 26996.073 ms
(3 rows)

Twenty-seven seconds of sleep on a vacuum whose predecessors in the same log reported a seventh of a second of elapsed work. On a twenty-thousand-row table. Nothing in the elapsed time, the CPU time or any counter on 17 would have told you that, and this is a cluster deliberately misconfigured rather than a pathological one: the settings that produced it are a delay of twenty milliseconds against a cost limit of twenty, which is not far outside the range people reach for when they are trying to stop maintenance interfering with a workload.

Two things about the log line are worth knowing before you build on it. It appears only when the setting is on, so a log-parsing rule has to tolerate its absence rather than treat a missing line as zero. And it is part of the multi-line autovacuum summary, which means it arrives indented and attached to the message above it, which is how the output above renders it and is a thing log shippers handle in different and occasionally surprising ways.

What to do with the number once you have it

• Turn the setting on across the fleet, with a reload. The measurement is a timer around a sleep the server was doing anyway, which is the cheapest kind of instrumentation there is.
• Add the delay total to whatever already parses the autovacuum log lines, and alert on the ratio of delay to elapsed rather than on either alone. A vacuum that is mostly asleep is a configuration finding, not an incident.
• When the ratio is high, raise the cost limit rather than lowering the delay. They are interchangeable arithmetically and not operationally: the limit is how much work happens between naps, and raising it gets the same throughput with fewer context switches.
• Leave the per-table overrides alone until the cluster-wide picture is clear. A table with its own storage parameters is invisible in a cluster-wide diagnosis, and chasing one before the general setting is right is how an afternoon disappears.

Turning a ratio into a setting

A delay ratio is only useful if it leads somewhere, and the arithmetic between the measurement and the setting is short enough to do in your head.

The throttle works on accumulated cost rather than on time. Vacuum adds up a notional cost as it works, and when the total passes the configured limit it sleeps for the configured delay and starts again. So the work the server is willing to do per second is the limit divided by the delay, in cost units, and every other number follows from that ratio rather than from either value alone.

The cluster measured above allows twenty cost units per twenty milliseconds, which is a thousand a second. A page that has to be dirtied costs twenty of those, so the cluster will let vacuum dirty about fifty pages a second, which is under half a megabyte. That is the entire explanation for a vacuum that runs for hours on a table that would take a minute to rewrite, and it is a number you can compute for any cluster from two settings without measuring anything.

The default settings are much more generous than the ones used here, and the delay ratio is the thing that tells you whether they are generous enough for a particular table. A ratio near zero means the throttle is not engaged and the settings are irrelevant to that table’s problem. A ratio near one means the throttle is the entire cost and the arithmetic above gives you the ceiling you are hitting.

When you decide to loosen it, raise the cost limit rather than lowering the delay. The two are interchangeable in the ratio and not in behaviour: raising the limit gets the same throughput with fewer pauses, which is easier on the storage and on the process scheduler than waking up more often to do less. And change it for the cluster before reaching for per-table storage parameters, because a per-table override is invisible in every cluster-wide diagnosis and will be forgotten by whoever inherits the database.

What it costs

The timing is a clock reading either side of a sleep that already happens, so the overhead is bounded by how often vacuum pauses rather than by how much work it does. That is a fundamentally cheaper proposition than the general I/O timing switch, which pays a clock reading per operation, and it is the reason this one is reasonable to leave on everywhere.

The progress views themselves cost nothing and are available whether or not the setting is on; only the delay column is gated. Both views show only vacuums running at the moment you look, which is the usual limitation of progress reporting and is why the log line matters as much as the column does.