From 6bfb33088cea797020886f73c1cfdb5a3290e0eb Mon Sep 17 00:00:00 2001 From: Masahiko Sawada Date: Thu, 8 Oct 2026 11:26:15 -0700 Subject: [PATCH] Fix parallel vacuum I/O timing reporting. Commit 5cd72cc0c5 made the VACUUM VERBOSE and autovacuum logs report buffer usage from the pgBufferUsage delta, which includes the parallel workers' usage, but left the I/O timings on the leader's pgStatBlockReadTime and pgStatBlockWriteTime. So the log counted the blocks the workers read and dirtied but not the time they spent on them. Fix this by taking the I/O timings from the same BufferUsage delta. This also removes a small error in the leader's own timings, since pgStatBlock{Read,Write}Time accumulate whole microseconds per I/O. Although 5cd72cc0c5 was backpatched to v15, BufferUsage on v16 doesn't track the I/O time of temporary relations, so the same fix there would drop that time from the log. We don't think a reporting issue is worth v16-specific code, nor worth leaving v16 unfixed between v15 and v17, so backpatch to v17 only. Found by Bharath using AI assisted review with Claude. Reported-by: Bharath Rupireddy Author: Bharath Rupireddy Reviewed-by: Sami Imseih Reviewed-by: Chao Li Reviewed-by: Masahiko Sawada Reviewed-by: Shihao Zhong Discussion: https://postgr.es/m/CALj2ACXrqaHrYmGdpAoGKXtiY9Xw4o1dxSC+EELxn47GDO6HAQ@mail.gmail.com Backpatch-through: 17 --- src/backend/access/heap/vacuumlazy.c | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 989fb491e55..e359e45dcd4 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -627,8 +627,6 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, new_rel_allfrozen; PGRUsage ru0; TimestampTz starttime = 0; - PgStat_Counter startreadtime = 0, - startwritetime = 0; WalUsage startwalusage = pgWalUsage; BufferUsage startbufferusage = pgBufferUsage; ErrorContextCallback errcallback; @@ -638,14 +636,7 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, instrument = (verbose || (AmAutoVacuumWorkerProcess() && params->log_min_duration >= 0)); if (instrument) - { pg_rusage_init(&ru0); - if (track_io_timing) - { - startreadtime = pgStatBlockReadTime; - startwritetime = pgStatBlockWriteTime; - } - } /* Used for instrumentation and stats report */ starttime = GetCurrentTimestamp(); @@ -1115,8 +1106,17 @@ heap_vacuum_rel(Relation rel, VacuumParams *params, } if (track_io_timing) { - double read_ms = (double) (pgStatBlockReadTime - startreadtime) / 1000; - double write_ms = (double) (pgStatBlockWriteTime - startwritetime) / 1000; + /* + * Take the timings from the same buffer usage delta as the + * block counts, so that the parallel workers are included in + * both. + */ + double read_ms = + INSTR_TIME_GET_MILLISEC(bufferusage.shared_blk_read_time) + + INSTR_TIME_GET_MILLISEC(bufferusage.local_blk_read_time); + double write_ms = + INSTR_TIME_GET_MILLISEC(bufferusage.shared_blk_write_time) + + INSTR_TIME_GET_MILLISEC(bufferusage.local_blk_write_time); appendStringInfo(&buf, _("I/O timings: read: %.3f ms, write: %.3f ms\n"), read_ms, write_ms);