Subject: Re: New WAL record to detect the checkpoint redo location

From: Andres Freund <[email-masked]>
Date: Thu, 5 Oct 2023 11:34:00 -0700

Hi,

On 2023-10-02 10:42:37 -0400, Robert Haas wrote:
> I was trying to think of a test case where XLogInsertRecord would be
> exercised as heavily as possible, so I really wanted to generate a lot
> of WAL while doing as little real work as possible. The best idea that
> I had was to run pg_create_restore_point() in a loop.

What I use for that is pg_logical_emit_message(). Something like

SELECT count(*)
FROM
    (
        SELECT pg_logical_emit_message(false, '1', 'short'), generate_series(1, 10000)
    );

run via pgbench does seem to exercise that path nicely.

> One possible conclusion is that the differences here aren't actually
> big enough to get stressed about, but I don't want to jump to that
> conclusion without investigating the competing hypothesis that this
> isn't the right way to test this, and that some better test would show
> clearer results. Suggestions?

I saw some small differences in runtime running pgbench with the above query,
with a single client. Comparing profiles showed a surprising degree of
difference. That turns out to mostly a consequence of the fact that
ReserveXLogInsertLocation() isn't inlined anymore, because there now are two
callers of the function in XLogInsertRecord().

Unfortunately, I still see a small performance difference after that. To get
the most reproducible numbers, I disable turbo boost, bound postgres to one
cpu core, bound pgbench to another core. Over a few runs I quite reproducibly
get ~319.323 tps with your patches applied (+ always inline), and ~324.674
with master.

If I add an unlikely around if (rechdr->xl_rmid == RM_XLOG_ID), the
performance does improve. But that "only" brings it up to 322.406. Not sure
what the rest is.

One thing that's notable, but not related to the patch, is that we waste a
fair bit of cpu time below XLogInsertRecord() with divisions. I think they're
all due to the use of UsableBytesInSegment in
XLogBytePosToRecPtr/XLogBytePosToEndRecPtr.  The multiplication of
XLogSegNoOffsetToRecPtr() also shows.

Greetings,

Andres Freund

---

From: Robert Haas <[email-masked]>
Date: Mon, 9 Oct 2023 15:58:36 -0400

> XLogSegNoOffsetToRecPtr() also shows.

Despite what I said in my earlier email, and with a feeling like unto
that created by the proximity of the sword of Damocles or some ghostly
albatross, I spent some time reflecting on this. Some observations:

1. The reason why we're doing this multiplication and division is to
make sure that the code in ReserveXLogInsertLocation which executes
while holding insertpos_lck remains as simple and brief as possible.
We could eliminate the conversion between usable byte positions and
LSNs if we replaced Insert->{Curr,Prev}BytePos with LSNs and had
ReserveXLogInsertLocation work out by how much to advance the LSN, but
it would have to be worked out while holding insertpos_lck (or some
replacement lwlock, perhaps) and that cure seems worse than the
disease. Given that, I think we're stuck with converting between
usable bye positions and LSNs, and that intrinsically needs some
multiplication and division.

2. It seems possible to remove one branch in each of
XLogBytePosToRecPtr and XLogBytePosToEndRecPtr. Rather than testing
whether bytesleft < XLOG_BLCKSZ - SizeOfXLogLongPHD, we could simply
increment bytesleft by SizeOfXLogLongPHD - SizeOfXLogShortPHD. Then
the rest of the calculations can be performed as if every page in the
segment had a header of length SizeOfXLogShortPHD, with no need to
special-case the first page. However, that doesn't get rid of any
multiplication or division, just a branch.

3. Aside from that, there seems to be no simple way to reduce the
complexity of an individual calculation, but ReserveXLogInsertLocation
does perform 3 rather similar computations, and I believe that we know
that it will always be the case that *PrevPtr < *StartPos < *EndPos.
Maybe we could have a fast-path for the case where they are all in the
same segment. We could take prevbytepos modulo UsableBytesInSegment;
call the result prevsegoff. If UsableBytesInSegment - prevsegoff >
endbytepos - prevbytepos, then all three pointers are in the same
segment, and maybe we could take advantage of that to avoid performing
the segment calculations more than once, but still needing to repeat
the page calculations. Or, instead or in addition, I think we could by
a similar technique check whether all three pointers are on the same
page; if so, then *StartPos and *EndPos can be computed from *PrevPtr
by just adding the difference between the corresponding byte
positions.

I'm not really sure whether that would come out cheaper. It's just the
only idea that I have. It did also occur to me to wonder whether the
apparent delays performing multiplication and division here were
really the result of the arithmetic itself being slow or whether they
were synchronization-related, SpinLockRelease(&Insert->insertpos_lck)
being a memory barrier just before. But I assume you thought about
that and concluded that wasn't the issue here.

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

---

From: Andres Freund <[email-masked]>
Date: Mon, 9 Oct 2023 13:47:02 -0700

Hi,

As noted in my email from a few minutes ago, I agree that optimizing this
shouldn't be a requirement for merging the patch.

> multiplication and division.

Right, that's absolutely crucial for scalability.

> multiplication or division, just a branch.

This reminded me about something I've been bugged by for a while: The whole
idea of short xlog page headers seems like a completely premature
optimization.  The page header is a very small amount of the overall data
(long: 40/8192 ~= 0.00488, short: 24/8192 ~= 0.00292), compared to the space
we waste in many other places, including on a per-record level, it doesn't
seem worth the complexity.

> by just adding the difference between the corresponding byte

I think we might be able to speed some of this up by pre-compute values so we
can implement things like bytesleft / UsableBytesInPage with shifts. IIRC we
already insist on power-of-two segment sizes, so instead of needing to divide
by a runtime value, we should be able to shift by a runtime value (and the
modulo should be a mask).

> that and concluded that wasn't the issue here.

I did verify that they continue to be a bottleneck even after (incorrectly
obviously), removing the spinlock. It's also not too surprising, the latency
of 64bit divs is just high, particularly on intel from a few years ago (my
cascade lake workstation) and IIRC there's just a single execution port for it
too, so multiple instructions can't be fully parallelized.

https://uops.info/table.html documents a worst case latency of 89 cycles on
cascade lake, with the division broken up into 36 uops (reducing what's
available to track other in-flight instructions). It's much better on alter
lake (9 cycles and 7 uops on the perf cores, 44 cycles and 4 uops on
efficiency cores) and on zen 3+ (19 cycles, 2 uops).

Greetings,

Andres Freund

---

From: Robert Haas <[email-masked]>
Date: Tue, 10 Oct 2023 14:43:34 -0400

> shouldn't be a requirement for merging the patch.

Here's a new patch set. I think I've incorporated the performance
fixes that you've suggested so far into this version. I also adjusted
a couple of other things:

- After further study of a point previously raised by Amit, I adjusted
CreateCheckPoint slightly to call WALInsertLockAcquireExclusive
significantly later than before. I think that there's no real reason
to do it so early and that the current coding is probably just a
historical leftover, but it would be good to have some review here.

- I added a cross-check that when starting redo from a checkpoint
whose redo pointer points to an earlier LSN that the checkpoint
itself, the record we read from that LSN must an XLOG_CHECKPOINT_REDO
record.

- I combined what were previously 0002 and 0003 into a single patch,
since that's how this would get committed.

- I fixed up some comments.

- I updated commit messages.

Hopefully this is getting close to good enough.

> too, so multiple instructions can't be fully parallelized.

The chipset on my laptop is even older. Coffee Lake, I think.

I'm not really sure that there's a whole lot we can reasonably do
about the divs unless you like the fastpath idea that I proposed
earlier, or unless you want to write a patch to either get rid of
short page headers or make long and short page headers the same number
of bytes. I have to admit I'm surprised by how visible the division
overhead is in this code path -- but I'm also somewhat inclined to
view that less as evidence that division is something we should be
desperate to eliminate and more as evidence that this code path is
quite fast already. In light of your findings, it doesn't seem
completely impossible to me that the speed of integer division in this
code path could be part of what limits performance for some users, but
I'm also not sure it's all that likely or all that serious, because
we're deliberating creating test cases that insert unreasonable
amounts of WAL without doing any actual work. In the real world,
there's going to be a lot more other code running along with this code
- probably at least the executor and some heap AM code - and I bet not
all of that is as well-optimized as this is already. And it's also
quite likely for many users that the real limits on the speed of the
workload will be related to I/O or lock contention rather than CPU
cost in any form. I'm not saying it's not worth worrying about it. I'm
just saying that we should make sure the amount of worrying we do is
calibrated to the true importance of the issue.

---

From: Michael Paquier <[email-masked]>
Date: Thu, 12 Oct 2023 16:27:19 +0900

> Hopefully this is getting close to good enough.

I have looked at 0001, for now..  And it looks OK to me.

+        * Nonetheless, this case is simpler than the normal cases handled
+        * above, which must check for changes in doPageWrites and RedoRecPtr.
+        * Those checks are only needed for records that can contain
+        * full-pages images, and an XLOG_SWITCH record never does.
+        Assert(fpw_lsn == InvalidXLogRecPtr);

Right, that's the core reason behind the refactoring.  The assertion
is a good idea.
--
Michael

---

From: Robert Haas <[email-masked]>
Date: Thu, 12 Oct 2023 14:10:31 -0400

> I have looked at 0001, for now..  And it looks OK to me.

Cool. I've committed that one. Thanks for the review.

---

From: Michael Paquier <[email-masked]>
Date: Fri, 13 Oct 2023 16:29:12 +0900

> a couple of other things:

Now looking at 0002, where you should be careful about the code
indentation or koel will complain.

> historical leftover, but it would be good to have some review here.

This makes the new code call LocalSetXLogInsertAllowed() and what we
set for checkPoint.PrevTimeLineID after taking the insertion locks,
which should be OK.

> itself, the record we read from that LSN must an XLOG_CHECKPOINT_REDO

I've mentioned as well a test in pg_walinspect after one of the
checkpoints generated there, but what you do here is enough for the
online case.

+       /*
+        * XLogInsertRecord will have updated RedoRecPtr, but we need to copy
+        * that into the record that will be inserted when the checkpoint is
+        * complete.
+        */
+       checkPoint.redo = RedoRecPtr;

For online checkpoints, a very important point is that
XLogCtl->Insert.RedoRecPtr is also updated in XLogInsertRecord().
Perhaps that's worth an addition?  I was a bit confused first that we
do the following for shutdown checkpoints:
RedoRecPtr = XLogCtl->Insert.RedoRecPtr = checkPoint.redo;

Then repeat this pattern for non-shutdown checkpoints a few lines down
without touching the copy of the redo LSN in XLogCtl->Insert, because
of course we don't hold the WAL insert locks in an exclusive fashion
here:
checkPoint.redo = RedoRecPtr;

My point is that this is not only about RedoRecPtr, but also about
XLogCtl->Insert.RedoRecPtr here.  The comment in ReserveXLogSwitch()
says that.
--
Michael

---

From: Robert Haas <[email-masked]>
Date: Tue, 17 Oct 2023 12:45:52 -0400

> indentation or koel will complain.

Fixed in the attached version.

> set for checkPoint.PrevTimeLineID after taking the insertion locks,

Cool.

> checkpoints generated there, but what you do here is enough for the

I don't quite understand what you're saying here. If you're suggesting
a potential improvement, can you be a bit more clear and explicit
about what the suggestion is?

> XLogCtl->Insert.RedoRecPtr here.  The comment in ReserveXLogSwitch()

I have adjusted the comment in CreateCheckPoint to hopefully address
this concern.  I don't understand what you mean about
ReserveXLogSwitch(), though.

---

From: Michael Paquier <[email-masked]>
Date: Wed, 18 Oct 2023 09:35:17 +0900

> about what the suggestion is?

Suggestion is from here, with a test for pg_walinspect after it runs
its online checkpoint (see the full-page case):
https://www.postgresql.org/message-id/ZOvf1tu6rfL/[email-masked]

+-- Check presence of REDO record.
+SELECT redo_lsn FROM pg_control_checkpoint() \gset
+SELECT start_lsn = :'redo_lsn'::pg_lsn AS same_lsn, record_type
+  FROM pg_get_wal_record_info(:'redo_lsn');

> this concern.

-        * XLogInsertRecord will have updated RedoRecPtr, but we need to copy
-        * that into the record that will be inserted when the checkpoint is
-        * complete.
+        * XLogInsertRecord will have updated XLogCtl->Insert.RedoRecPtr in
+        * shared memory and RedoRecPtr in backend-local memory, but we need
+        * to copy that into the record that will be inserted when the
+        * checkpoint is complete. 

This comment diff between v8 and v9 looks OK to me.  Thanks.

> I don't understand what you mean about

I am not sure either, looking back at that :p
--
Michael

---

From: Robert Haas <[email-masked]>
Date: Wed, 18 Oct 2023 10:24:50 -0400

> +  FROM pg_get_wal_record_info(:'redo_lsn');

I added a variant of this test case. Here's v10.

---

From: Michael Paquier <[email-masked]>
Date: Thu, 19 Oct 2023 14:53:12 +0900

> I added a variant of this test case. Here's v10.

+-- Verify that an XLOG_CHECKPOINT_REDO record begins at precisely the redo LSN
+-- of the checkpoint we just performed.
+SELECT redo_lsn FROM pg_control_checkpoint() \gset
+SELECT start_lsn = :'redo_lsn'::pg_lsn AS same_lsn, resource_manager,
+    record_type FROM pg_get_wal_record_info(:'redo_lsn');
+ same_lsn | resource_manager |   record_type   
+----------+------------------+-----------------
+ t        | XLOG             | CHECKPOINT_REDO
+(1 row)

Seems fine to me.  Thanks for considering the idea.
--
Michael

---

From: Robert Haas <[email-masked]>
Date: Thu, 19 Oct 2023 14:48:56 -0400

> Seems fine to me.  Thanks for considering the idea.

I think it was a good idea!

I've committed the patch.