mirror of
https://github.com/postgres/postgres.git
synced 2026-10-23 13:29:09 +03:00
Fix parallel vacuum I/O timing reporting.
Commit5cd72cc0c5made 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. Although5cd72cc0c5was 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 <bharath.rupireddyforpostgres@gmail.com> Author: Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com> Reviewed-by: Sami Imseih <samimseih.pg@gmail.com> Reviewed-by: Chao Li <li.evan.chao@gmail.com> Reviewed-by: Masahiko Sawada <sawada.mshk@gmail.com> Reviewed-by: Shihao Zhong <zhong950419@gmail.com> Discussion: https://postgr.es/m/CALj2ACXrqaHrYmGdpAoGKXtiY9Xw4o1dxSC+EELxn47GDO6HAQ@mail.gmail.com Backpatch-through: 17
This commit is contained in:
@@ -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);
|
||||
|
||||
Reference in New Issue
Block a user