pg.ddx.io pgsql-hackers@postgresql.org mailing list archive
help / color / mirror / Atom feedRE: [EXTERNAL] Re: WIP: WAL prefetch (another approach)
6+ messages / 3 participants
[nested] [flat]
* RE: [EXTERNAL] Re: WIP: WAL prefetch (another approach)
@ 2020-09-01 06:14 Sait Talha Nisanci <Sait.Nisanci@microsoft.com>
0 siblings, 0 replies; 6+ messages in thread
From: Sait Talha Nisanci @ 2020-09-01 06:14 UTC (permalink / raw)
To: Stephen Frost <sfrost@snowman.net>; Tomas Vondra <tomas.vondra@2ndquadrant.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Thomas Munro <thomas.munro@gmail.com>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
Hi,
The WAL size for "SSD, full_page_writes=on" was 36GB. I currently don't have the exact size for the other rows because my test VMs got auto-deleted. I can possibly redo the benchmark to get pg_waldump stats for each row.
Best,
Talha.
-----Original Message-----
From: Stephen Frost <sfrost@snowman.net>
Sent: Sunday, August 30, 2020 3:24 PM
To: Tomas Vondra <tomas.vondra@2ndquadrant.com>
Cc: Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Sait Talha Nisanci <Sait.Nisanci@microsoft.com>; Thomas Munro <thomas.munro@gmail.com>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: [EXTERNAL] Re: WIP: WAL prefetch (another approach)
Greetings,
* Tomas Vondra (tomas.vondra@2ndquadrant.com) wrote:
> On Thu, Aug 27, 2020 at 04:28:54PM -0400, Stephen Frost wrote:
> >* Robert Haas (robertmhaas@gmail.com) wrote:
> >>On Thu, Aug 27, 2020 at 2:51 PM Stephen Frost <sfrost@snowman.net> wrote:
> >>> > Hm? At least earlier versions didn't do prefetching for records with an fpw, and only for subsequent records affecting the same or if not in s_b anymore.
> >>>
> >>> We don't actually read the page when we're replaying an FPW though..?
> >>> If we don't read it, and we entirely write the page from the FPW,
> >>> how is pre-fetching helping..?
> >>
> >>Suppose there is a checkpoint. Then we replay a record with an FPW,
> >>pre-fetching nothing. Then the buffer gets evicted from
> >>shared_buffers, and maybe the OS cache too. Then, before the next
> >>checkpoint, we again replay a record for the same page. At this
> >>point, pre-fetching should be helpful.
> >
> >Sure- but if we're talking about 25GB of WAL, on a server that's got
> >32GB, then why would those pages end up getting evicted from memory
> >entirely? Particularly, enough of them to end up with such a huge
> >difference in replay time..
> >
> >I do agree that if we've got more outstanding WAL between checkpoints
> >than the system's got memory then that certainly changes things, but
> >that wasn't what I understood the case to be here.
>
> I don't think it's very clear how much WAL there actually was in each
> case - the message only said there was more than 25GB, but who knows
> how many checkpoints that covers? In the cases with FPW=on this may
> easily be much less than one checkpoint (because with scale 45GB an
> update to every page will log 45GB of full-page images). It'd be
> interesting to see some stats from pg_waldump etc.
Also in the message was this:
--
In order to avoid checkpoints during benchmark, max_wal_size(200GB) and
checkpoint_timeout(200 mins) are set to a high value.
--
Which lead me to suspect, at least, that this was much less than a checkpoint, as you suggest. Also, given that the comment was 'run is cancelled when there is a reasonable amount of WAL (>25GB), seems likely that it's at least *around* there.
Ultimately though, there just isn't enough information provided to really be able to understand what's going on. I agree, pg_waldump stats would be useful.
> >>Admittedly, I don't quite understand whether that is what is
> >>happening in this test case, or why SDD vs. HDD should make any
> >>difference. But there doesn't seem to be any reason why it doesn't
> >>make sense in theory.
> >
> >I agree that this could be a reason, but it doesn't seem to quite fit
> >in this particular case given the amount of memory and WAL. I'm
> >suspecting that it's something else and I'd very much like to know if
> >it's a general "this applies to all (most? a lot of?) SSDs because
> >the hardware has a larger than 8KB page size and therefore the kernel
> >has to read it", or if it's something odd about this particular
> >system and doesn't apply generally.
>
> Not sure. I doubt it has anything to do with the hardware page size,
> that's mostly transparent to the kernel anyway. But it might be that
> the prefetching on a particular SSD has more overhead than what it saves.
Right- I wouldn't have thought the hardware page size would matter either, but it's entirely possible that assumption is wrong and that it does matter for some reason- perhaps with just some SSDs, or maybe with a lot of them, or maybe there's something else entirely going on. About all I feel like I can say at the moment is that I'm very interested in ways to make WAL replay go faster and it'd be great to get more information about what's going on here to see if there's something we can do to generally improve WAL replay.
Thanks,
Stephen
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: WIP: WAL prefetch (another approach)
@ 2020-09-01 13:14 Tomas Vondra <tomas.vondra@2ndquadrant.com>
0 siblings, 1 reply; 6+ messages in thread
From: Tomas Vondra @ 2020-09-01 13:14 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@gmail.com>; +Cc: Stephen Frost <sfrost@snowman.net>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Andres Freund <andres@anarazel.de>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
On Thu, Aug 13, 2020 at 06:57:20PM +1200, Thomas Munro wrote:
>On Thu, Aug 6, 2020 at 10:47 PM Tomas Vondra
><tomas.vondra@2ndquadrant.com> wrote:
>> On Thu, Aug 06, 2020 at 02:58:44PM +1200, Thomas Munro wrote:
>> >On Tue, Aug 4, 2020 at 3:47 AM Tomas Vondra
>> >> Any luck trying to reproduce thigs? Should I try again and collect some
>> >> additional debug info?
>> >
>> >No luck. I'm working on it now, and also trying to reduce the
>> >overheads so that we're not doing extra work when it doesn't help.
>>
>> OK, I'll see if I can still reproduce it.
>
>Since someone else ask me off-list, here's a rebase, with no
>functional changes. Soon I'll post a new improved version, but this
>version just fixes the bitrot and hopefully turns cfbot green.
I've decided to do some tests with this patch version, but I immediately
ran into issues. What I did was initializing a 32GB pgbench database,
backed it up (shutdown + tar) and then ran 2h pgbench with archiving.
And then I restored the backed-up data directory and instructed it to
replay WAL from the archive. There's about 16k WAL segments, so about
256GB of WAL.
Unfortunately, the very first thing that happens after starting the
recovery is this:
LOG: starting archive recovery
LOG: restored log file "000000010000001600000080" from archive
LOG: consistent recovery state reached at 16/800000A0
LOG: redo starts at 16/800000A0
LOG: database system is ready to accept read only connections
LOG: recovery started prefetching on timeline 1 at 0/800000A0
LOG: recovery no longer prefetching: unexpected pageaddr 8/84000000 in log segment 000000010000001600000081, offset 0
LOG: restored log file "000000010000001600000081" from archive
LOG: restored log file "000000010000001600000082" from archive
So we start applying 000000010000001600000081 and it fails almost
immediately on the first segment. This is confirmed by prefetch stats,
which look like this:
-[ RECORD 1 ]---+-----------------------------
stats_reset | 2020-09-01 15:02:31.18766+02
prefetch | 1044
skip_hit | 1995
skip_new | 87
skip_fpw | 2108
skip_seq | 27
distance | 0
queue_depth | 0
avg_distance | 135838.95
avg_queue_depth | 8.852459
So we do a little bit of prefetching and then it gets disabled :-(
The segment looks perfectly fine when inspected using pg_waldump, see
the attached file.
I've tested this applied on 6ca547cf75ef6e922476c51a3fb5e253eef5f1b6,
and the failure seems fairly similar to what I reported before, except
that now it happened right at the very beginning.
regards
--
Tomas Vondra http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Attachments:
000000010000001600000081.log.gz (application/gzip, 99.4K) download
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: WIP: WAL prefetch (another approach)
@ 2020-09-01 14:05 Thomas Munro <thomas.munro@gmail.com>
parent: Tomas Vondra <tomas.vondra@2ndquadrant.com>
0 siblings, 1 reply; 6+ messages in thread
From: Thomas Munro @ 2020-09-01 14:05 UTC (permalink / raw)
To: Tomas Vondra <tomas.vondra@2ndquadrant.com>; +Cc: Stephen Frost <sfrost@snowman.net>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Andres Freund <andres@anarazel.de>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
On Wed, Sep 2, 2020 at 1:14 AM Tomas Vondra
<tomas.vondra@2ndquadrant.com> wrote:
> from the archive
Ahh, so perhaps that's the key.
> I've tested this applied on 6ca547cf75ef6e922476c51a3fb5e253eef5f1b6,
> and the failure seems fairly similar to what I reported before, except
> that now it happened right at the very beginning.
Thanks, will see if I can work out why. My newer version probably has
the same problem.
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: WIP: WAL prefetch (another approach)
@ 2020-09-01 14:18 Tomas Vondra <tomas.vondra@2ndquadrant.com>
parent: Thomas Munro <thomas.munro@gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Tomas Vondra @ 2020-09-01 14:18 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@gmail.com>; +Cc: Stephen Frost <sfrost@snowman.net>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Andres Freund <andres@anarazel.de>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
On Wed, Sep 02, 2020 at 02:05:10AM +1200, Thomas Munro wrote:
>On Wed, Sep 2, 2020 at 1:14 AM Tomas Vondra
><tomas.vondra@2ndquadrant.com> wrote:
>> from the archive
>
>Ahh, so perhaps that's the key.
>
Maybe. For the record, the commands look like this:
archive_command = 'gzip -1 -c %p > /mnt/raid/wal-archive/%f.gz'
restore_command = 'gunzip -c /mnt/raid/wal-archive/%f.gz > %p.tmp && mv %p.tmp %p'
>> I've tested this applied on 6ca547cf75ef6e922476c51a3fb5e253eef5f1b6,
>> and the failure seems fairly similar to what I reported before, except
>> that now it happened right at the very beginning.
>
>Thanks, will see if I can work out why. My newer version probably has
>the same problem.
OK.
regards
--
Tomas Vondra http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: WIP: WAL prefetch (another approach)
@ 2020-09-05 00:05 Thomas Munro <thomas.munro@gmail.com>
parent: Tomas Vondra <tomas.vondra@2ndquadrant.com>
0 siblings, 1 reply; 6+ messages in thread
From: Thomas Munro @ 2020-09-05 00:05 UTC (permalink / raw)
To: Tomas Vondra <tomas.vondra@2ndquadrant.com>; +Cc: Stephen Frost <sfrost@snowman.net>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Andres Freund <andres@anarazel.de>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
On Wed, Sep 2, 2020 at 2:18 AM Tomas Vondra
<tomas.vondra@2ndquadrant.com> wrote:
> On Wed, Sep 02, 2020 at 02:05:10AM +1200, Thomas Munro wrote:
> >On Wed, Sep 2, 2020 at 1:14 AM Tomas Vondra
> ><tomas.vondra@2ndquadrant.com> wrote:
> >> from the archive
> >
> >Ahh, so perhaps that's the key.
>
> Maybe. For the record, the commands look like this:
>
> archive_command = 'gzip -1 -c %p > /mnt/raid/wal-archive/%f.gz'
>
> restore_command = 'gunzip -c /mnt/raid/wal-archive/%f.gz > %p.tmp && mv %p.tmp %p'
Yeah, sorry, I goofed here by not considering archive recovery
properly. I have special handling for crash recovery from files in
pg_wal (XLRO_END, means read until you run out of files) and streaming
replication (XLRO_WALRCV_WRITTEN, means read only as far as the wal
receiver has advertised as written in shared memory), as a way to
control the ultimate limit on how far ahead to read when
maintenance_io_concurrency and max_recovery_prefetch_distance don't
limit you first. But if you recover from a base backup with a WAL
archive, it uses the XLRO_END policy which can run out of files just
because a new file hasn't been restored yet, so it gives up
prefetching too soon, as you're seeing. That doesn't cause any
damage, but it stops doing anything useful because the prefetcher
thinks its job is finished.
It'd be possible to fix this somehow in the two-XLogReader design, but
since I'm testing a new version that has a unified
XLogReader-with-read-ahead I'm not going to try to do that. I've
added a basebackup-with-archive recovery to my arsenal of test
workloads to make sure I don't forget about archive recovery mode
again, but I think it's actually harder to get this wrong in the new
design. In the meantime, if you are still interested in studying the
potential speed-up from WAL prefetching using the most recently shared
two-XLogReader patch, you'll need to unpack all your archived WAL
files into pg_wal manually beforehand.
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: WIP: WAL prefetch (another approach)
@ 2020-09-08 23:16 Tomas Vondra <tomas.vondra@2ndquadrant.com>
parent: Thomas Munro <thomas.munro@gmail.com>
0 siblings, 0 replies; 6+ messages in thread
From: Tomas Vondra @ 2020-09-08 23:16 UTC (permalink / raw)
To: Thomas Munro <thomas.munro@gmail.com>; +Cc: Stephen Frost <sfrost@snowman.net>; Dmitry Dolgov <9erthalion6@gmail.com>; David Steele <david@pgmasters.net>; Andres Freund <andres@anarazel.de>; Alvaro Herrera <alvherre@2ndquadrant.com>; pgsql-hackers
On Sat, Sep 05, 2020 at 12:05:52PM +1200, Thomas Munro wrote:
>On Wed, Sep 2, 2020 at 2:18 AM Tomas Vondra
><tomas.vondra@2ndquadrant.com> wrote:
>> On Wed, Sep 02, 2020 at 02:05:10AM +1200, Thomas Munro wrote:
>> >On Wed, Sep 2, 2020 at 1:14 AM Tomas Vondra
>> ><tomas.vondra@2ndquadrant.com> wrote:
>> >> from the archive
>> >
>> >Ahh, so perhaps that's the key.
>>
>> Maybe. For the record, the commands look like this:
>>
>> archive_command = 'gzip -1 -c %p > /mnt/raid/wal-archive/%f.gz'
>>
>> restore_command = 'gunzip -c /mnt/raid/wal-archive/%f.gz > %p.tmp && mv %p.tmp %p'
>
>Yeah, sorry, I goofed here by not considering archive recovery
>properly. I have special handling for crash recovery from files in
>pg_wal (XLRO_END, means read until you run out of files) and streaming
>replication (XLRO_WALRCV_WRITTEN, means read only as far as the wal
>receiver has advertised as written in shared memory), as a way to
>control the ultimate limit on how far ahead to read when
>maintenance_io_concurrency and max_recovery_prefetch_distance don't
>limit you first. But if you recover from a base backup with a WAL
>archive, it uses the XLRO_END policy which can run out of files just
>because a new file hasn't been restored yet, so it gives up
>prefetching too soon, as you're seeing. That doesn't cause any
>damage, but it stops doing anything useful because the prefetcher
>thinks its job is finished.
>
>It'd be possible to fix this somehow in the two-XLogReader design, but
>since I'm testing a new version that has a unified
>XLogReader-with-read-ahead I'm not going to try to do that. I've
>added a basebackup-with-archive recovery to my arsenal of test
>workloads to make sure I don't forget about archive recovery mode
>again, but I think it's actually harder to get this wrong in the new
>design. In the meantime, if you are still interested in studying the
>potential speed-up from WAL prefetching using the most recently shared
>two-XLogReader patch, you'll need to unpack all your archived WAL
>files into pg_wal manually beforehand.
OK, thanks for looking into this. I guess I'll wait for an updated patch
before testing this further. The storage has limited capacity so I'd
have to either reduce the amount of data/WAL or juggle with the WAL
segments somehow. Doesn't seem worth it.
regards
--
Tomas Vondra http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2020-09-08 23:16 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2020-09-01 06:14 RE: [EXTERNAL] Re: WIP: WAL prefetch (another approach) Sait Talha Nisanci <Sait.Nisanci@microsoft.com>
2020-09-01 13:14 Re: WIP: WAL prefetch (another approach) Tomas Vondra <tomas.vondra@2ndquadrant.com>
2020-09-01 14:05 ` Thomas Munro <thomas.munro@gmail.com>
2020-09-01 14:18 ` Tomas Vondra <tomas.vondra@2ndquadrant.com>
2020-09-05 00:05 ` Thomas Munro <thomas.munro@gmail.com>
2020-09-08 23:16 ` Tomas Vondra <tomas.vondra@2ndquadrant.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox