pg_stat_progress_copy, and the frozen row

A statement that runs for an hour and says nothing

COPY is the statement every restore, every bulk load and every migration cutover is built on, and until PostgreSQL 14 it was completely opaque while it ran. A session showed active and the statement text, and that was the whole of the server’s contribution. Operators guessed from outside: watch the table’s file size grow, watch the input file being read, or compare against how long it took last time.

PostgreSQL 14 gave it a progress view, in the same family as the ones vacuum and index builds already had. It reports bytes read from the source, bytes expected where that is knowable, rows inserted, and rows a WHERE clause excluded. The System Views section of the release notes carries it, first of the four views that arrived in that release.

The column that disappoints people is the byte total, and the reason is worth understanding before you build a percentage on it. The server knows how large the source is only when the source is a file it opened itself. A COPY streaming from a client connection has no total, because the client has not said how much it intends to send, and neither does one reading from a program’s output. In both of those cases the total is zero and a naive percentage divides by it.

Watching a load from inside the load

Observing a progress view normally needs a second session, which makes it awkward to demonstrate honestly. There is a way to do it from inside a single one: a row trigger on the target table runs in the same backend as the copy, while the copy is in progress, so it can read the progress row for its own process and write what it saw into a scratch table.

CREATE TABLE shipment (id integer, sku text, qty integer);
CREATE TABLE copy_watch (at_row integer, reading text, source text,
                         bytes bigint, byte_total bigint, tuples bigint);
CREATE FUNCTION watch_copy() RETURNS trigger LANGUAGE plpgsql AS $$
DECLARE r record;
BEGIN
  IF NEW.id % 40000 = 0 THEN
    SELECT type, bytes_processed, bytes_total, tuples_processed INTO r
      FROM pg_stat_progress_copy WHERE pid = pg_backend_pid();
    INSERT INTO copy_watch
      VALUES (NEW.id, 'cached', r.type, r.bytes_processed, r.bytes_total, r.tuples_processed);
    PERFORM pg_stat_clear_snapshot();
    SELECT type, bytes_processed, bytes_total, tuples_processed INTO r
      FROM pg_stat_progress_copy WHERE pid = pg_backend_pid();
    INSERT INTO copy_watch
      VALUES (NEW.id, 'fresh', r.type, r.bytes_processed, r.bytes_total, r.tuples_processed);
  END IF;
  RETURN NEW;
END $$;
CREATE TRIGGER watch BEFORE INSERT ON shipment
  FOR EACH ROW EXECUTE FUNCTION watch_copy();

CREATE TABLE
CREATE TABLE
CREATE FUNCTION
CREATE TRIGGER

COPY shipment FROM PROGRAM 'seq 1 100000 | awk ''{print $1"\tSKU-"$1"\t"($1%7)}''';
SELECT * FROM copy_watch ORDER BY at_row, reading;

COPY 100000
 at_row | reading | source  |  bytes  | byte_total | tuples 
--------+---------+---------+---------+------------+--------
  40000 | cached  | PROGRAM |  720896 |          0 |  39999
  40000 | fresh   | PROGRAM |  720896 |          0 |  39999
  80000 | cached  | PROGRAM |  720896 |          0 |  39999
  80000 | fresh   | PROGRAM | 1441792 |          0 |  79999
(4 rows)

Read those four rows in pairs. At forty thousand rows the cached and the fresh reading agree. At eighty thousand they do not: the cached one still reports the forty-thousand figures, and only the fresh one has moved.

That is not a bug in the view. Every statistics view in PostgreSQL is served from a snapshot taken the first time a transaction reads one, and the snapshot is discarded when the transaction ends. A COPY is a single statement inside a single transaction, so a query that reads the progress row twice within it reads the same row twice. pg_stat_clear_snapshot() is the escape hatch, and it is documented with the statistics machinery generally rather than anywhere near the progress views.

This bites in practice in a way that has nothing to do with triggers. A monitoring session that opens a transaction, polls every progress view in turn, and stays in that transaction across polls will report a load that never advances. The fix is to end the transaction between polls, or to call the clear function, and the symptom is indistinguishable from a genuinely stuck load.

The other thing visible in that output is the byte total, which is zero throughout, because the source was a program rather than a file. Give the server a file it opened itself and the same column fills in.

DELETE FROM copy_watch;
COPY shipment TO '/tmp/shipment.tsv';
TRUNCATE shipment;
COPY shipment FROM '/tmp/shipment.tsv';
SELECT * FROM copy_watch ORDER BY at_row, reading;

DELETE 4
COPY 100000
TRUNCATE TABLE
COPY 100000
 at_row | reading | source |  bytes  | byte_total | tuples 
--------+---------+--------+---------+------------+--------
  40000 | cached  | FILE   |  720896 |    1777790 |  39999
  40000 | fresh   | FILE   |  720896 |    1777790 |  39999
  80000 | cached  | FILE   |  720896 |    1777790 |  39999
  80000 | fresh   | FILE   | 1441792 |    1777790 |  79999
(4 rows)

Same rows, same readings, and now a denominator. The source column is what tells you which case you are in without reading the statement text, and a percentage is worth showing a human only when it says FILE. A restore driven over a client connection, which is what most restore tools do, reports something else and a total of zero for the whole run.

What this looks like after the upgrade

The view is an addition rather than a change, so nothing here breaks on the way out of 14. One column was added later, and it is worth knowing about because it changes what a row count means.

SELECT string_agg(attname, ', ' ORDER BY attnum) AS columns
FROM pg_attribute
WHERE attrelid = 'pg_stat_progress_copy'::regclass AND attnum > 0;

On 14:

                                                  columns                                                   
------------------------------------------------------------------------------------------------------------
 pid, datid, datname, relid, command, type, bytes_processed, bytes_total, tuples_processed, tuples_excluded
(1 row)

On 18:

                                                          columns                                                           
----------------------------------------------------------------------------------------------------------------------------
 pid, datid, datname, relid, command, type, bytes_processed, bytes_total, tuples_processed, tuples_excluded, tuples_skipped
(1 row)

The extra column counts rows the server was told to skip after a conversion error, which is a facility 17 added to COPY itself. On 14 a bad row ends the statement, so tuples_processed plus tuples_excluded is the whole story and a load either finishes or does not. From 17 a load can complete having quietly discarded input, and a dashboard that only graphs processed rows will show a clean finish. If you move a restore pipeline onto a newer major, add that column to whatever you record, because it is the one that says the load was lossy.

The same snapshot behaviour survives the upgrade, incidentally. The statistics collector was replaced in 15, but the per-transaction snapshot is a property of how backend status is read rather than of where the counters live, and the frozen row is still frozen on 18.

What a restore looks like through this view

The case most people want this for is a restore, and a restore is not one copy. The dump tool issues a COPY per table over a client connection, one after another in a single job and several at a time in a parallel one, so the view holds one row per backend currently loading something and the row for a given table appears and disappears as its turn comes.

That shapes how you read it. The relation column tells you which table each row is loading, which is the one thing the statement text cannot tell you reliably because the tool sends it qualified in its own way. A parallel restore gives you a row per worker, and the useful summary is the count of rows, which is how many tables are in flight, next to the processed totals, which is how much of the work is done.

What it cannot give you is the shape of the whole job. There is no total, because the source is a client connection, and there is no list of tables still to come, because the server has not been told there is a job at all. A progress bar for a restore has to come from outside the database, from the tool’s own output, and this view is what tells you whether the table currently being loaded is moving or stuck.

The other common case is the opposite direction. A COPY TO gets a row as well, and on an export the byte total is again zero, because the destination size is not known in advance either. The processed count is still the useful number, and for an export it is the only one.

Who is running it

The progress row identifies the work and not the worker. It has a process identifier, a database and a relation, and no statement text, no user and no application name, which is deliberate: those already exist one join away in the activity view, and duplicating them would mean two places for them to disagree.

So the query worth keeping in a runbook joins the two on the process identifier and takes the relation from the progress row and everything else from the activity row. That gives you the table being loaded, the client that asked for it, how long the statement has been running, and what it is currently waiting on, which together are enough to decide whether a slow load is slow because of the source, the target or something else holding a lock.

The join is also the only way to notice a load that is not progressing because it is blocked. The progress row of a backend waiting on a lock looks exactly like the progress row of a backend that has finished its last batch: the counters simply stop. The wait event beside it is what separates those, and it is not in this view.

Worth watching rather than alerting on

There is no threshold to put on a progress view, and inventing one would be worse than saying so. Two things earn a place on a screen during a cutover.

• Rows per second, computed from two samples taken in different transactions. Compare it against the same load’s previous run rather than against an absolute figure.
• The gap between processed and excluded rows, when the load carries a WHERE clause. A filter matching more than you expected is the failure that finishes on time and delivers the wrong data.

What to alert on is the absence of the row, not its contents: a load that was supposed to be running and has no progress row has either finished or died, and the difference matters more than any rate.

What it costs to observe

Nothing gates the view and nothing needs restarting. The counters are incremented by the copy itself into shared memory it already writes to, and reading them is a scan of the backend status array.

The cost that catches people is the one above: reading the view is free, reading it correctly requires ending a transaction or clearing a snapshot between samples. A poller that gets that wrong pays nothing and reports a lie, which is the more expensive of the two outcomes.

For a load large enough to be worth watching, the other views to have open are the write-ahead log counters, because a bulk load is usually the largest single log producer a cluster sees, and if the target is replicated, whichever slot is carrying it.