Re: Show WAL write and fsync stats in pg_stat_io

Hi,

On Wed, 5 Feb 2025 at 21:32, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:
>
> Michael Paquier <michael(at)paquier(dot)xyz> writes:
> > At the end, we want this patch and this data, and my benchmarcking is
> > not showing much differences even if going through a workload with
> > many pages, so I've used the version relying entirely on
> > track_io_timing and applied it.
>
> Locally, the test added by this commit fails like so:
>
> diff -U3 /home/postgres/pgsql/src/test/regress/expected/stats.out /home/postgres
> /pgsql/src/test/regress/results/stats.out
> --- /home/postgres/pgsql/src/test/regress/expected/stats.out 2025-02-04 12:33
> :07.456393545 -0500
> +++ /home/postgres/pgsql/src/test/regress/results/stats.out 2025-02-05 13:08
> :30.605638432 -0500
> @@ -886,7 +886,7 @@
> WHERE context = 'normal' AND object = 'wal';
> ?column?
> ----------
> - t
> + f
> (1 row)
>
> -----
>
> This is pretty repeatable (not perfectly so) in a build with
> --enable-debug --enable-cassert --enable-tap-tests --with-llvm
> but it usually passes without --with-llvm. System is fairly
> up-to-date RHEL8 on x86_64. No idea why the buildfarm isn't
> unhappy. Any pointers where to look?

Thanks for the report!

My thoughts when adding this test was that startup process must do the
WAL read I/O while server is starting, i.e.:

'''
startup process ->
InitWalRecovery ->
ReadCheckpointRecord ->
ReadRecord ->
XLogPrefetcherReadRecord ->
lrq_complete_lsn ->
lrq_prefetch ->
lrq->next = XLogPrefetcherNextBlock ->
XLogReadAhead ->
XLogDecodeNextRecord ->
ReadPageInternal ->
state->routine.page_read = XLogPageRead()
'''

Is there a chance that the function chain above does not get triggered
while running the stats.sql test?

--
Regards,
Nazir Bilal Yavuz
Microsoft