Re: Refactor CheckpointWriteDelay()

> Given that CheckpointWriteDelay() is really a hot code path i.e. gets
> called for every dirty buffer written to disk, here's an opportunity
> for us to improve it by avoiding some function calls.

I have reviewed the patch and I agree that the patch improves the code.

> Firstly, the AmCheckpointerProcess() macro check can be placed outside
> of the CheckpointWriteDelay() which avoids function calls (dirty
> buffers written to disk * one function call cost) for a
> non-checkpointer process(standalone backend) performing checkpoint.

It definitely improves the code as it reduces one function call per
dirty buffer write during non-checkpointer process even though we may
not see huge performance improvement during testing. But I am not in
favour of this change as many existing functions use this kind of
check in the initial part of the function. The other reason is, if we
call this function in multiple places in future then we may end up
having multiple checks or we may have to revert back the code.

> Secondly, remove the function ImmediateCheckpointRequested() and read
> the ckpt_flags from the CheckpointerShmem with volatile qualifier.
> This saves some LOC and cost = dirty buffers written to disk * one
> function call cost. The ImmediateCheckpointRequested() really does
> nothing great, it just reads from the shared memory without lock and
> checks whether there's any immediate checkpoint request pending behind
> the current one.

+1 for this change.

> - * Perform the usual duties and take a nap, unless we're behind schedule,
> - * in which case we just try to catch up as quickly as possible.
> + * Perform the usual duties and take a nap, unless we're behind schedule or
> + * an immediate checkpoint request is pending, in which case we just try to
> + * catch up as quickly as possible.
> + *
> + * We don't need to acquire the ckpt_lck while reading ckpt_flags from
> + * checkpointer shared memory, because we're only looking at a single flag
> + * bit.

+1 for the additional information. I feel the information related to
the pending shutdown request should also be added.

Thanks & Regards,
Nitin Jadhav

On Thu, Feb 10, 2022 at 5:32 PM Bharath Rupireddy
<bharath(dot)rupireddyforpostgres(at)gmail(dot)com> wrote:
>
> Hi,
>
> Given that CheckpointWriteDelay() is really a hot code path i.e. gets
> called for every dirty buffer written to disk, here's an opportunity
> for us to improve it by avoiding some function calls.
>
> Firstly, the AmCheckpointerProcess() macro check can be placed outside
> of the CheckpointWriteDelay() which avoids function calls (dirty
> buffers written to disk * one function call cost) for a
> non-checkpointer process(standalone backend) performing checkpoint.
>
> Secondly, remove the function ImmediateCheckpointRequested() and read
> the ckpt_flags from the CheckpointerShmem with volatile qualifier.
> This saves some LOC and cost = dirty buffers written to disk * one
> function call cost. The ImmediateCheckpointRequested() really does
> nothing great, it just reads from the shared memory without lock and
> checks whether there's any immediate checkpoint request pending behind
> the current one.
>
> Attaching a patch with the above changes. Please have a look at it.
>
> I did a small experiment[1] with a use case [2] on my dev system where
> I measured the total time spent in CheckpointWriteDelay() with and
> without patch, to my surprise, I didn't see much difference. It may be
> my experiment is wrong, my dev box doesn't show much diff and others
> may or may not notice the difference. Despite this, the patch proposed
> still helps IMO as it saves a few LOC (16) and I'm sure it will also
> save some time for standalone backend checkpoints.
>
> Other hackers may not agree with me on the readability (IMO, the patch
> doesn't make it unreadable) or the diff that it creates with the
> previous versions and so on. I'd rather argue that
> CheckpointWriteDelay() is really a hot code path in production
> environments and the patch proposed has some benefits.
>
> Thoughts?
>
> [1] see "write delay" at the end of "checkpoint complete" message:
> HEAD:
> 2022-02-08 05:56:45.551 UTC [651784] LOG: checkpoint starting: time
> 2022-02-08 05:57:39.154 UTC [651784] LOG: checkpoint complete: wrote
> 14740 buffers (90.0%); 0 WAL file(s) added, 0 removed, 27 recycled;
> write=53.461 s, sync=0.027 s, total=53.604 s; sync files=22,
> longest=0.016 s, average=0.002 s; distance=438865 kB, estimate=438865
> kB; write delay=53104.194 ms
>
> 2022-02-08 05:59:24.173 UTC [652589] LOG: checkpoint starting: time
> 2022-02-08 06:00:18.166 UTC [652589] LOG: checkpoint complete: wrote
> 14740 buffers (90.0%); 0 WAL file(s) added, 0 removed, 27 recycled;
> write=53.848 s, sync=0.030 s, total=53.993 s; sync files=22,
> longest=0.017 s, average=0.002 s; distance=438865 kB, estimate=438865
> kB; write delay=53603.159 ms
>
> PATCHED:
> 2022-02-08 06:07:26.286 UTC [662667] LOG: checkpoint starting: time
> 2022-02-08 06:08:20.152 UTC [662667] LOG: checkpoint complete: wrote
> 14740 buffers (90.0%); 0 WAL file(s) added, 0 removed, 27 recycled;
> write=53.732 s, sync=0.026 s, total=53.867 s; sync files=22,
> longest=0.016 s, average=0.002 s; distance=438865 kB, estimate=438865
> kB; write delay=53399.582 ms
>
> 2022-02-08 06:10:17.554 UTC [663393] LOG: checkpoint starting: time
> 2022-02-08 06:11:11.163 UTC [663393] LOG: checkpoint complete: wrote
> 14740 buffers (90.0%); 0 WAL file(s) added, 0 removed, 27 recycled;
> write=53.488 s, sync=0.023 s, total=53.610 s; sync files=22,
> longest=0.018 s, average=0.002 s; distance=438865 kB, estimate=438865
> kB; write delay=53099.114 ms
>
> [2]
> checkpoint_timeout = 60s
> create table t1(a1 int, b1 int);
> /* inserted 7mn rows */
> insert into t1 select i, i*2 from generate_series(1, 7000000) i;
>
> Regards,
> Bharath Rupireddy.