| From: | Masahiko Sawada <sawada(dot)mshk(at)gmail(dot)com> |
|---|---|
| To: | Chao Li <li(dot)evan(dot)chao(at)gmail(dot)com> |
| Cc: | Bharath Rupireddy <bharath(dot)rupireddyforpostgres(at)gmail(dot)com>, PostgreSQL Hackers <pgsql-hackers(at)lists(dot)postgresql(dot)org> |
| Subject: | Re: Parallel vacuum: I/O timings in the log leave out the parallel workers |
| Date: | 2026-09-29 06:08:37 |
| Message-ID: | CAD21AoB8tTvP08P3JJ+fJN9nihFFiD81xGog5sWABS7MbsN2FA@mail.gmail.com |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-hackers |
On Mon, Sep 28, 2026 at 7:45 PM Chao Li <li(dot)evan(dot)chao(at)gmail(dot)com> wrote:
>
>
>
> > On Sep 28, 2026, at 08:15, Bharath Rupireddy <bharath(dot)rupireddyforpostgres(at)gmail(dot)com> wrote:
> >
> > Hi,
> >
> > AI review identified an inconsistency in parallel vacuum (5cd72cc0c5).
> > I checked it myself and it is there on HEAD and on every branch since
> > PG15. Patch attached, [2] has the reproducer. I don't think
> > back-patching is necessary as it's not a bug, only what the log
> > reports.
> >
> > 5cd72cc0c5 made the buffer usage in the VACUUM VERBOSE and autovacuum
> > log lines come from the pgBufferUsage delta, which includes what the
> > parallel workers did, but left the I/O timings on the leader's own
> > pgStatBlockReadTime and pgStatBlockWriteTime, which nothing folds the
> > workers' time into. So the same log line counts the blocks the workers
> > read and dirtied without the time they spent on them, and the time per
> > block computed from it comes out too low. [1] shows it before and
> > after.
> >
> > The fix takes the timings from the same buffer usage delta as the
> > block counts. A worker accumulates its buffer usage, timings included,
> > into its own pgBufferUsage, and the leader folds that into its own
> > with InstrAccumParallelQuery() once an index phase is done. The shared
> > and the local fields are summed, so a temporary table keeps the
> > numbers it had, pgStatBlockReadTime having counted local blocks too.
> > It also stops the leader's own share from coming out slightly low,
> > pgStatBlockReadTime and pgStatBlockWriteTime being fed whole
> > microseconds per I/O while the BufferUsage fields keep the full
> > instr_time.
> >
> > [1] The same vacuum with two workers, before and after the patch.
> >
> > Before:
> >
> > I/O timings: read: 179.511 ms, write: 149.717 ms
> >
> > After:
> >
> > I/O timings: read: 236.303 ms, write: 215.114 ms
> >
> > The difference in write time is what the workers spent, which
> > pg_stat_io accounts to them and the log left out. Read time also moves
> > around on its own with the OS page cache.
> >
> > [2] With track_io_timing = on, shared_buffers = 1MB and autovacuum = off:
> >
> > CREATE TABLE t (a int, b int, c int) WITH (autovacuum_enabled = off);
> > INSERT INTO t SELECT i, i, i FROM generate_series(1, 2000000) i;
> > CREATE INDEX t_a_idx ON t (a);
> > CREATE INDEX t_b_idx ON t (b);
> > CREATE INDEX t_c_idx ON t (c);
> > DELETE FROM t WHERE a % 4 = 0;
> >
> > Restart the server so that nothing is left in shared buffers, then:
> >
> > SELECT pg_stat_reset_shared('io');
> >
> > Run the vacuum in a session of its own, so that the client backend row below is
> > the leader and nothing else:
> >
> > VACUUM (VERBOSE, PARALLEL 2) t;
> >
> > Then from another session:
> >
> > SELECT backend_type, context, round(read_time::numeric, 3) AS read_ms,
> > round(write_time::numeric, 3) AS write_ms, reads, writes
> > FROM pg_stat_io WHERE read_time > 0 OR write_time > 0
> > ORDER BY 1, 2;
> >
> > --
> > Bharath Rupireddy
> > Amazon Web Services: https://aws.amazon.com
> > <v1-0001-Include-parallel-workers-in-the-I-O-timings-repor.patch>
>
> Switching to pgBufferUsage looks correct to me. 5cd72cc0c5 switched the hit, read, and dirtied counts to pgBufferUsage, but seems to have missed the read and write timings. Since that fix was back-patched through v15, should this fix be back-patched through v15 as well?
Yes, I think we should treat it the same way as 5cd72cc0c5.
We need to note that in 16 BufferUsage doesn't have
local_blk_{read|write}_time, and pgstat_count_io_op_time() adds the
I/O time of temp relations only to pgStatBlockReadTime and
pgStatBlockWRiteTime, not to BufferUsage.blk_{read|write}_time. So
taking the timings from BufferUsage would drop the time spent on temp
relations from the log. In 15, blk_{read|write}_time and
pgStatBlock{Read|Write}TIme cover the same I/O, so the fix would be
straightforward, but I don't think it's worth leaving 16 unfixed in
between, or adding 16-specific code for a reporting issue. So I'm
inclined to backpatch it to 17. Thoughts?
Regards,
--
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Chao Li | 2026-09-29 06:09:40 | pg_resetwal: Fix handling of commit timestamp XIDs |
| Previous Message | shihao zhong | 2026-09-29 06:02:00 | pg_resetwal: refuse to run when backup_label exists |