Обсуждение: pg_basebackup -x/X doesn't play well with archive_mode & wal_keep_segments

Hi,

We've recently observed a case where, after a promotion, a postgres
server suddenly started to archive a large amount of old WAL.

After some digging the problem is this:

pg_basebackup -X creates files in pg_xlog/ without creating the
corresponding .done file. Note that walreceiver *does* create them. The
standby in this case, just like the master, had a significant
wal_keep_segments.  RemoveOldXlogFiles() then, during recovery restart
points, calls XLogArchiveCheckDone() which in turn does:/* Retry creation of the .ready file */XLogArchiveNotify(xlog);
     return false;
 
if there's neither a .done nor a .ready file present and archive_mode is
enabled. These segments then aren't removed because there's a .ready
present and they're never archived as long as the node is a standby
because we don't do archiving on standbys.
Once the node is promoted archiver will be started and suddenly archive
all these files - which might be months old.

And additional, at first strange, nice detail is that a lot of the
.ready files had nearly the same timestamps. Turns out that's due to
wal_keep_segments. Initially RemoveOldXlogFiles() doesn't process the
files because they're newer than allowed due to wal_keep_segments. Then
every checkpoint a couple segments would be old enough to reach
XLogArchiveCheckDone() which then'd create the .ready marker... But not
all at once :)


So I think we just need to make pg_basebackup create to .ready
files. Given that the walreceiver and restore_command already
unconditionally do XLogArchiveForceDone() I think we'd follow the
established precedent. Arguably it could make sense to archive files
again on the standby after a promotion as they aren't guaranteed to have
been on the then primary. But we don't have any infrastructure anyway
for that and walsender doesn't do so, so it doesn't seem to make any
sense to do that for pg_basebackup.

Independent from this bug, there's also some debatable behaviour about
what happens if a node with a high wal_keep_segments turns on
archive_mode. Suddenly all those old files are archived... I think it
might be a good idea to simply always create .done files when
archive_mode is disabled while a wal segment is finished.

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

On Fri, Dec 5, 2014 at 9:28 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> Hi,
>
> We've recently observed a case where, after a promotion, a postgres
> server suddenly started to archive a large amount of old WAL.
>
> After some digging the problem is this:
>
> pg_basebackup -X creates files in pg_xlog/ without creating the
> corresponding .done file. Note that walreceiver *does* create them. The
> standby in this case, just like the master, had a significant
> wal_keep_segments.  RemoveOldXlogFiles() then, during recovery restart
> points, calls XLogArchiveCheckDone() which in turn does:
>         /* Retry creation of the .ready file */
>         XLogArchiveNotify(xlog);
>         return false;
> if there's neither a .done nor a .ready file present and archive_mode is
> enabled. These segments then aren't removed because there's a .ready
> present and they're never archived as long as the node is a standby
> because we don't do archiving on standbys.
> Once the node is promoted archiver will be started and suddenly archive
> all these files - which might be months old.
>
> And additional, at first strange, nice detail is that a lot of the
> .ready files had nearly the same timestamps. Turns out that's due to
> wal_keep_segments. Initially RemoveOldXlogFiles() doesn't process the
> files because they're newer than allowed due to wal_keep_segments. Then
> every checkpoint a couple segments would be old enough to reach
> XLogArchiveCheckDone() which then'd create the .ready marker... But not
> all at once :)
>
>
> So I think we just need to make pg_basebackup create to .ready
> files.

s/.ready/.done? If yes, +1.

> Given that the walreceiver and restore_command already
> unconditionally do XLogArchiveForceDone() I think we'd follow the
> established precedent. Arguably it could make sense to archive files
> again on the standby after a promotion as they aren't guaranteed to have
> been on the then primary. But we don't have any infrastructure anyway
> for that and walsender doesn't do so, so it doesn't seem to make any
> sense to do that for pg_basebackup.
>
> Independent from this bug, there's also some debatable behaviour about
> what happens if a node with a high wal_keep_segments turns on
> archive_mode. Suddenly all those old files are archived... I think it
> might be a good idea to simply always create .done files when
> archive_mode is disabled while a wal segment is finished.

+1

Regards,

-- 
Fujii Masao

Hi,

On 2014-12-05 16:18:02 +0900, Fujii Masao wrote:
> On Fri, Dec 5, 2014 at 9:28 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > So I think we just need to make pg_basebackup create to .ready
> > files.
>
> s/.ready/.done? If yes, +1.

That unfortunately requires changes to both backend and pg_basebackup to
support fetch and stream modes respectively.

I've attached a preliminary patch for this. I'd appreciate feedback. I
plan to commit it in a couple of days, after some more
testing/rereading.

> > Given that the walreceiver and restore_command already
> > unconditionally do XLogArchiveForceDone() I think we'd follow the
> > established precedent. Arguably it could make sense to archive files
> > again on the standby after a promotion as they aren't guaranteed to have
> > been on the then primary. But we don't have any infrastructure anyway
> > for that and walsender doesn't do so, so it doesn't seem to make any
> > sense to do that for pg_basebackup.
> >
> > Independent from this bug, there's also some debatable behaviour about
> > what happens if a node with a high wal_keep_segments turns on
> > archive_mode. Suddenly all those old files are archived... I think it
> > might be a good idea to simply always create .done files when
> > archive_mode is disabled while a wal segment is finished.
>
> +1

I tend to think that's a master only change. Agreed?

Greetings,

Andres Freund

On 2014-12-31 16:32:19 +0100, Andres Freund wrote:
> On 2014-12-05 16:18:02 +0900, Fujii Masao wrote:
> > On Fri, Dec 5, 2014 at 9:28 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > > So I think we just need to make pg_basebackup create to .ready
> > > files.
> >
> > s/.ready/.done? If yes, +1.
>
> That unfortunately requires changes to both backend and pg_basebackup to
> support fetch and stream modes respectively.
>
> I've attached a preliminary patch for this. I'd appreciate feedback. I
> plan to commit it in a couple of days, after some more
> testing/rereading.

Attached are two updated patches that I am starting to backport
now. I've fixed a couple minor oversights. And tested the patches.

Greetings,

Andres Freund

--
 Andres Freund                       http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On 2015-01-03 16:03:36 +0100, Andres Freund wrote:
> On 2014-12-31 16:32:19 +0100, Andres Freund wrote:
> > On 2014-12-05 16:18:02 +0900, Fujii Masao wrote:
> > > On Fri, Dec 5, 2014 at 9:28 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > > > So I think we just need to make pg_basebackup create to .ready
> > > > files.
> > > 
> > > s/.ready/.done? If yes, +1.
> > 
> > That unfortunately requires changes to both backend and pg_basebackup to
> > support fetch and stream modes respectively.
> > 
> > I've attached a preliminary patch for this. I'd appreciate feedback. I
> > plan to commit it in a couple of days, after some more
> > testing/rereading.
> 
> Attached are two updated patches that I am starting to backport
> now. I've fixed a couple minor oversights. And tested the patches.

Pushed this after some major pain with backporting. pg_basebackup really
changed heavily since it's introduction. And desparately needs some
restructuring.

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

On Sun, Jan 4, 2015 at 5:47 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2015-01-03 16:03:36 +0100, Andres Freund wrote:
>> On 2014-12-31 16:32:19 +0100, Andres Freund wrote:
>> > On 2014-12-05 16:18:02 +0900, Fujii Masao wrote:
>> > > On Fri, Dec 5, 2014 at 9:28 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>> > > > So I think we just need to make pg_basebackup create to .ready
>> > > > files.
>> > >
>> > > s/.ready/.done? If yes, +1.
>> >
>> > That unfortunately requires changes to both backend and pg_basebackup to
>> > support fetch and stream modes respectively.
>> >
>> > I've attached a preliminary patch for this. I'd appreciate feedback. I
>> > plan to commit it in a couple of days, after some more
>> > testing/rereading.
>>
>> Attached are two updated patches that I am starting to backport
>> now. I've fixed a couple minor oversights. And tested the patches.
>
> Pushed this after some major pain with backporting.

Thanks!

> pg_basebackup really
> changed heavily since it's introduction. And desparately needs some
> restructuring.

The patch seems to break pg_receivexlog. I got the following error message
while running pg_receivexlog.

pg_receivexlog: could not create archive status file
"mmm/archive_status/000000010000000000000003.done": No such file or
directory

Regards,

-- 
Fujii Masao

On 2015-01-05 16:22:56 +0900, Fujii Masao wrote:
> On Sun, Jan 4, 2015 at 5:47 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > On 2015-01-03 16:03:36 +0100, Andres Freund wrote:
> > pg_basebackup really
> > changed heavily since it's introduction. And desparately needs some
> > restructuring.
> 
> The patch seems to break pg_receivexlog. I got the following error message
> while running pg_receivexlog.

> pg_receivexlog: could not create archive status file
> "mmm/archive_status/000000010000000000000003.done": No such file or
> directory

Dang. Stupid typo. And my tests didn't catch it, because I had
archive_directory in the target directory :(

At least it's only broken in master :/

Thanks for the catch. Do you have some additional testsuite or did you
catch it manually?

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

On Mon, Jan 5, 2015 at 6:22 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2015-01-05 16:22:56 +0900, Fujii Masao wrote:
>> On Sun, Jan 4, 2015 at 5:47 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>> > On 2015-01-03 16:03:36 +0100, Andres Freund wrote:
>> > pg_basebackup really
>> > changed heavily since it's introduction. And desparately needs some
>> > restructuring.
>>
>> The patch seems to break pg_receivexlog. I got the following error message
>> while running pg_receivexlog.
>
>> pg_receivexlog: could not create archive status file
>> "mmm/archive_status/000000010000000000000003.done": No such file or
>> directory
>
> Dang. Stupid typo. And my tests didn't catch it, because I had
> archive_directory in the target directory :(
>
> At least it's only broken in master :/
>
> Thanks for the catch. Do you have some additional testsuite or did you
> catch it manually?

Manually... I just tested the tools and options which the patch may affect...

Regards,

-- 
Fujii Masao

On 2015-01-05 18:49:06 +0900, Fujii Masao wrote:
> On Mon, Jan 5, 2015 at 6:22 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> > On 2015-01-05 16:22:56 +0900, Fujii Masao wrote:
> >> On Sun, Jan 4, 2015 at 5:47 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> >> > On 2015-01-03 16:03:36 +0100, Andres Freund wrote:
> >> > pg_basebackup really
> >> > changed heavily since it's introduction. And desparately needs some
> >> > restructuring.
> >>
> >> The patch seems to break pg_receivexlog. I got the following error message
> >> while running pg_receivexlog.
> >
> >> pg_receivexlog: could not create archive status file
> >> "mmm/archive_status/000000010000000000000003.done": No such file or
> >> directory
> >
> > Dang. Stupid typo. And my tests didn't catch it, because I had
> > archive_directory in the target directory :(
> >
> > At least it's only broken in master :/

I've pushed the trivial fix, and verified using my adapted testscript
that it works on all branches.

> > Thanks for the catch. Do you have some additional testsuite or did you
> > catch it manually?
> 
> Manually... I just tested the tools and options which the patch may affect...

Thanks!

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

Hi,

On Mon, Jan 5, 2015 at 4:34 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>> >> pg_receivexlog: could not create archive status file
>> >> "mmm/archive_status/000000010000000000000003.done": No such file or
>> >> directory
>> >
>> > Dang. Stupid typo. And my tests didn't catch it, because I had
>> > archive_directory in the target directory :(

I started getting these errors after upgrading from 9.2.8 to 9.2.10.
Is it something critical that requires version downgrade or I can just
ignore that errors?

-- 
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA

http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (499) 346-7196, +7 (988) 888-1979
gray.ru@gmail.com

On February 12, 2015 8:11:05 PM CET, Sergey Konoplev <gray.ru@gmail.com> wrote:
>Hi,
>
>On Mon, Jan 5, 2015 at 4:34 AM, Andres Freund <andres@2ndquadrant.com>
>wrote:
>>> >> pg_receivexlog: could not create archive status file
>>> >> "mmm/archive_status/000000010000000000000003.done": No such file
>or
>>> >> directory
>>> >
>>> > Dang. Stupid typo. And my tests didn't catch it, because I had
>>> > archive_directory in the target directory :(
>
>I started getting these errors after upgrading from 9.2.8 to 9.2.10.
>Is it something critical that requires version downgrade or I can just
>ignore that errors?

What errors are you getting in precisely which circumstances? You're using pg-receivexlog? 

-- 
Please excuse brevity and formatting - I am writing this on my mobile phone.

Andres Freund                       http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

On Thu, Feb 12, 2015 at 11:13 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>>I started getting these errors after upgrading from 9.2.8 to 9.2.10.
>>Is it something critical that requires version downgrade or I can just
>>ignore that errors?
>
> What errors are you getting in precisely which circumstances? You're using pg-receivexlog?

Errors like this one

pg_receivexlog: could not create archive status file
"/mnt/archive/wal/archive_status/00000004000002AF000000B7.done": No
such file or directory
pg_receivexlog: disconnected..

on

Linux xyz 3.2.0-76-generic #111-Ubuntu SMP
PostgreSQL 9.2.10

Yes, I use pg_receivexlog. I also use a wrapper/watchdog script around
pg_receivexlog which tracks failures and restarts the latter.

The WAL files time correlates with the pg_receivexlog failures.

postgres@xyz:~$ ls -ltr /mnt/archive/wal/ | tail
-rw------- 1 postgres postgres 16777216 Feb 12 10:58 00000004000002B600000011
-rw------- 1 postgres postgres 16777216 Feb 12 11:02 00000004000002B600000012
-rw------- 1 postgres postgres 16777216 Feb 12 11:06 00000004000002B600000013
-rw------- 1 postgres postgres 16777216 Feb 12 11:11 00000004000002B600000014
-rw------- 1 postgres postgres 16777216 Feb 12 11:15 00000004000002B600000015
-rw------- 1 postgres postgres 16777216 Feb 12 11:19 00000004000002B600000016
-rw------- 1 postgres postgres 16777216 Feb 12 11:23 00000004000002B600000017
-rw------- 1 postgres postgres 16777216 Feb 12 11:27 00000004000002B600000018
-rw------- 1 postgres postgres 16777216 Feb 12 11:30 00000004000002B600000019
-rw------- 1 postgres postgres 16777216 Feb 12 11:32
00000004000002B60000001A.partial

postgres@xyz:~$ cat /var/log/pgcookbook/manage_pitr-wal.log | tail
Thu Feb 12 11:15:18 PST 2015 ERROR manage_pitr.sh: Problem occured
during WAL archiving: pg_receivexlog: could not create archive status
file "/mnt/archive/wal/archive_status/00000004000002B600000015.done":
No such file or directory
pg_receivexlog: disconnected..
Thu Feb 12 11:19:33 PST 2015 ERROR manage_pitr.sh: Problem occured
during WAL archiving: pg_receivexlog: could not create archive status
file "/mnt/archive/wal/archive_status/00000004000002B600000016.done":
No such file or directory
pg_receivexlog: disconnected..
Thu Feb 12 11:23:38 PST 2015 ERROR manage_pitr.sh: Problem occured
during WAL archiving: pg_receivexlog: could not create archive status
file "/mnt/archive/wal/archive_status/00000004000002B600000017.done":
No such file or directory
pg_receivexlog: disconnected..
Thu Feb 12 11:27:32 PST 2015 ERROR manage_pitr.sh: Problem occured
during WAL archiving: pg_receivexlog: could not create archive status
file "/mnt/archive/wal/archive_status/00000004000002B600000018.done":
No such file or directory
pg_receivexlog: disconnected..
Thu Feb 12 11:30:34 PST 2015 ERROR manage_pitr.sh: Problem occured
during WAL archiving: pg_receivexlog: could not create archive status
file "/mnt/archive/wal/archive_status/00000004000002B600000019.done":
No such file or directory
pg_receivexlog: disconnected..

-- 
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA

http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (499) 346-7196, +7 (988) 888-1979
gray.ru@gmail.com

Hi.

This obviously should not be the case. I'll have a look in a couple of hours. Until then you can likely  just work
aroundthe problem by creating the archive_status directory.
 
-- 
Please excuse brevity and formatting - I am writing this on my mobile phone.

Andres Freund                       http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

On Thu, Feb 12, 2015 at 11:40 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> This obviously should not be the case. I'll have a look in a couple of hours. Until then you can likely  just work
aroundthe problem by creating the archive_status directory.
 

Thank you. Just let me know if you need some extra info or debugging.

-- 
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA

http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (499) 346-7196, +7 (988) 888-1979
gray.ru@gmail.com

On 2015-02-12 11:44:05 -0800, Sergey Konoplev wrote:
> On Thu, Feb 12, 2015 at 11:40 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > This obviously should not be the case. I'll have a look in a couple of hours. Until then you can likely  just work
aroundthe problem by creating the archive_status directory.
 
> 
> Thank you. Just let me know if you need some extra info or debugging.

No need for debugging. It's plain and simply a (cherry-pick) conflict I
resolved wrongly during backpatching. 9.3, 9.4 and master do not have
that problem. That whole fix was quite painful because every single
release had significantly different code :(. pg_basebackup/ is pretty
messy.
I'm not sure why my testsuite didn't trigger that problem. Possibly
because a retry makes things work :(

Somewhat uckily it's 9.2 only (9.3, 9.4 and master look correct, earlier
releases don't have pg_receivexlog) and can quite easily be worked
around by creating the archive_status directory.

If you want to fix it locally, you just need to replace
ReceiveXlogStream(conn, startpos, timeline, NULL, basedir,                  stop_streaming, standby_message_timeout,
false,true);
 
by
ReceiveXlogStream(conn, startpos, timeline, NULL, basedir,                  stop_streaming, standby_message_timeout,
false,false);
 

Yes, that and pretty much all other functions in that directory have too
many parameters.

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

On Thu, Feb 12, 2015 at 4:18 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> No need for debugging. It's plain and simply a (cherry-pick) conflict I
> resolved wrongly during backpatching. 9.3, 9.4 and master do not have
> that problem. That whole fix was quite painful because every single
> release had significantly different code :(. pg_basebackup/ is pretty
> messy.
> I'm not sure why my testsuite didn't trigger that problem. Possibly
> because a retry makes things work :(
>
> Somewhat uckily it's 9.2 only (9.3, 9.4 and master look correct, earlier
> releases don't have pg_receivexlog) and can quite easily be worked
> around by creating the archive_status directory.

The workaround works perfectly for me in this case, I'm going to
updrade it up to 9.4 anyway soon.

Thank you, Andres.

-- 
Kind regards,
Sergey Konoplev
PostgreSQL Consultant and DBA

http://www.linkedin.com/in/grayhemp
+1 (415) 867-9984, +7 (499) 346-7196, +7 (988) 888-1979
gray.ru@gmail.com

On Fri, Feb 13, 2015 at 9:18 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2015-02-12 11:44:05 -0800, Sergey Konoplev wrote:
>> On Thu, Feb 12, 2015 at 11:40 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>> > This obviously should not be the case. I'll have a look in a couple of hours. Until then you can likely  just work
aroundthe problem by creating the archive_status directory.
 
>>
>> Thank you. Just let me know if you need some extra info or debugging.
>
> No need for debugging. It's plain and simply a (cherry-pick) conflict I
> resolved wrongly during backpatching. 9.3, 9.4 and master do not have
> that problem. That whole fix was quite painful because every single
> release had significantly different code :(. pg_basebackup/ is pretty
> messy.
> I'm not sure why my testsuite didn't trigger that problem. Possibly
> because a retry makes things work :(
>
> Somewhat uckily it's 9.2 only (9.3, 9.4 and master look correct, earlier
> releases don't have pg_receivexlog)

Are you planning to back-patch the fix to 9.2?

Regards,

-- 
Fujii Masao

On 2015-02-17 12:18:41 +0900, Fujii Masao wrote:
> On Fri, Feb 13, 2015 at 9:18 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > Somewhat uckily it's 9.2 only (9.3, 9.4 and master look correct, earlier
> > releases don't have pg_receivexlog)
> 
> Are you planning to back-patch the fix to 9.2?

Yes, but I want to look through all versions, to make sure there's no
other merge resolution mistakes lurking.

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services

On 2015-02-17 12:18:41 +0900, Fujii Masao wrote:
> On Fri, Feb 13, 2015 at 9:18 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> > On 2015-02-12 11:44:05 -0800, Sergey Konoplev wrote:
> >> On Thu, Feb 12, 2015 at 11:40 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> >> > This obviously should not be the case. I'll have a look in a couple of hours. Until then you can likely  just
workaround the problem by creating the archive_status directory.
 
> >>
> >> Thank you. Just let me know if you need some extra info or debugging.
> >
> > No need for debugging. It's plain and simply a (cherry-pick) conflict I
> > resolved wrongly during backpatching. 9.3, 9.4 and master do not have
> > that problem. That whole fix was quite painful because every single
> > release had significantly different code :(. pg_basebackup/ is pretty
> > messy.
> > I'm not sure why my testsuite didn't trigger that problem. Possibly
> > because a retry makes things work :(
> >
> > Somewhat uckily it's 9.2 only (9.3, 9.4 and master look correct, earlier
> > releases don't have pg_receivexlog)
> 
> Are you planning to back-patch the fix to 9.2?

Now done. Thanks Sergey, Fujii. And sorry for the 9.2 screwup.

Greetings,

Andres Freund

-- Andres Freund                       http://www.2ndQuadrant.com/PostgreSQL Development, 24x7 Support, Training &
Services