Re: Track IO times in pg_stat_io

Thanks for the review!

On Tue, Feb 28, 2023 at 4:49 AM Drouvot, Bertrand
<bertranddrouvot(dot)pg(at)gmail(dot)com> wrote:
> On 2/26/23 5:03 PM, Melanie Plageman wrote:
> > As suggested in [1], the attached patch adds IO times to pg_stat_io;
>
> Thanks for the patch!
>
> I started to have a look at it and figured out that a tiny rebase was needed (due to
> 728560db7d and b9f0e54bc9), so please find the rebase (aka V2) attached.

Thanks for doing that!

> > The timings will only be non-zero when track_io_timing is on
>
> That could lead to incorrect interpretation if one wants to divide the timing per operations, say:
>
> - track_io_timing is set to on while there is already operations
> - or set to off while it was on (and the number of operations keeps growing)
>
> Might be worth to warn/highlight in the "track_io_timing" doc?

This is a good point. I've added a note to the docs for pg_stat_io.

> + if (track_io_timing)
> + {
> + INSTR_TIME_SET_CURRENT(io_time);
> + INSTR_TIME_SUBTRACT(io_time, io_start);
> + pgstat_count_io_time(io_object, io_context, IOOP_EXTEND, io_time);
> + }
> +
> +
> pgstat_count_io_op(io_object, io_context, IOOP_EXTEND);
>
> vs
>
> @@ -1042,6 +1059,7 @@ ReadBuffer_common(SMgrRelation smgr, char relpersistence, ForkNumber forkNum,
> INSTR_TIME_SUBTRACT(io_time, io_start);
> pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time));
> INSTR_TIME_ADD(pgBufferUsage.blk_read_time, io_time);
> + pgstat_count_io_time(io_object, io_context, IOOP_READ, io_time);
> }
>
> That leads to pgstat_count_io_time() to be called before pgstat_count_io_op() (for the IOOP_EXTEND case) and
> after pgstat_count_io_op() (for the IOOP_READ case).
>
> What about calling them in the same order and so that pgstat_count_io_time() is called before pgstat_count_io_op()?
>
> If so, the ordering would also need to be changed in:
>
> - FlushRelationBuffers()
> - register_dirty_segment()

Yes, good point. I've updated the code to use this suggested ordering in
attached v3.

> > There is one minor question (in the code as a TODO) which is whether or
> > not it is worth cross-checking that IO counts and times are either both
> > zero or neither zero in the validation function
> > pgstat_bktype_io_stats_valid().
> >
>
> As pgstat_bktype_io_stats_valid() is called only in Assert(), I think that would be a good idea
> to also check that if counts are not Zero then times are not Zero.

Yes, I think adding some validation around the relationship between
counts and timing should help prevent developers from forgetting to call
pg_stat_count_io_op() when calling pgstat_count_io_time() (as relevant).

However, I think that we cannot check that if IO counts are non-zero
that IO times are non-zero, because the user may not have
track_io_timing enabled. We can check that if IO times are not zero, IO
counts are not zero. I've done this in the attached v3.

- Melanie