Re: pgBufferUsage.blk_{read|write}_time are zero although there are pgBufferUsage.local_blks_{read|written} - Mailing list pgsql-hackers

From Robert Haas
Subject Re: pgBufferUsage.blk_{read|write}_time are zero although there are pgBufferUsage.local_blks_{read|written}
Date
Msg-id CA+TgmoYv7prtCVJ-dHVwAWLJr5hXp+6bO7kiHRtgCrRr6FExWA@mail.gmail.com
Whole thread Raw
In response to Re: pgBufferUsage.blk_{read|write}_time are zero although there are pgBufferUsage.local_blks_{read|written}  (Melanie Plageman <melanieplageman@gmail.com>)
Responses Re: pgBufferUsage.blk_{read|write}_time are zero although there are pgBufferUsage.local_blks_{read|written}  (Nazir Bilal Yavuz <byavuz81@gmail.com>)
Re: pgBufferUsage.blk_{read|write}_time are zero although there are pgBufferUsage.local_blks_{read|written}  (Michael Paquier <michael@paquier.xyz>)
List pgsql-hackers
On Fri, Sep 15, 2023 at 12:34 PM Melanie Plageman
<melanieplageman@gmail.com> wrote:
> On Fri, Sep 15, 2023 at 9:24 AM Nazir Bilal Yavuz <byavuz81@gmail.com> wrote:
> > I found that pgBufferUsage.blk_{read|write}_time are zero although there are
pgBufferUsage.local_blks_{read|written}
>
> Yes, good catch. This is a bug. I will note that at least in 15 and
> likely before, pgBufferUsage.local_blks_written is incremented for
> local buffers but pgBufferUsage.blk_write_time is only added to for
> shared buffers (in FlushBuffer()). I think it makes sense to propose a
> bug fix to stable branches counting blk_write_time for local buffers
> as well.

My first thought was to wonder whether this was even a bug. I
remembered that EXPLAIN treats shared, local, and temp buffers as
three separate categories of things. But it seems that someone decided
to conflate two of them for I/O timing purposes:

                        if (has_timing)
                        {
                                appendStringInfoString(es->str, "
shared/local");

^^^^ Notice this bit in particular.

                                if (!INSTR_TIME_IS_ZERO(usage->blk_read_time))
                                        appendStringInfo(es->str, " read=%0.3f",

  INSTR_TIME_GET_MILLISEC(usage->blk_read_time));
                                if (!INSTR_TIME_IS_ZERO(usage->blk_write_time))
                                        appendStringInfo(es->str, "
write=%0.3f",

  INSTR_TIME_GET_MILLISEC(usage->blk_write_time));
                                if (has_temp_timing)
                                        appendStringInfoChar(es->str, ',');
                        }
                        if (has_temp_timing)
                        {
                                appendStringInfoString(es->str, " temp");
                                if
(!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time))
                                        appendStringInfo(es->str, " read=%0.3f",

  INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time));
                                if
(!INSTR_TIME_IS_ZERO(usage->temp_blk_write_time))
                                        appendStringInfo(es->str, "
write=%0.3f",

  INSTR_TIME_GET_MILLISEC(usage->temp_blk_write_time));
                        }

Given that, I'm inclined to agree that this is a bug. But we might
need to go through and make sure all of the code that deals with these
counters is on the same page about what the values represent. Maybe
there is code lurking somewhere that thinks these counters are only
supposed to include "shared" rather than, as the fragment above
suggests, "shared/local".

--
Robert Haas
EDB: http://www.enterprisedb.com



pgsql-hackers by date:

Previous
From: shveta malik
Date:
Subject: Re: Synchronizing slots from primary to standby
Next
From: Tom Lane
Date:
Subject: Re: Annoying build warnings from latest Apple toolchain