Re: problems using pg_start_backup/pg_stop_backup and pg_basebackup at same time

Thanks for the response Magnus.

I've replied inline below.

On Mon, Jun 20, 2016 at 4:17 AM, Magnus Hagander <magnus@hagander.net> wrote:

On Mon, Jun 13, 2016 at 6:59 PM, Alex Malek <magicagent@gmail.com> wrote:

I am experiencing two problems
1) pg_stop_backup hangs until pg_basebackup finishes

2) WAL contains references to invalid pages

(I suspect when 1. is fixed I won't experience 2. )

Full description below:

postgresql: 9.3.13

My situation is I create a writable report database every day using pg_start_backup() / rsync / pg_stop_backup()

(whole process takes 1-2 hours, the rsync actually copies the data dir of a  slave/warm spare DB)

Taking what is called an exclusive backup, which is what pg_start_backup() does, is not supported off a standby node. Only pg_basebackup is supported against a standby node.

Can you reproduce your errors if you make this backup from the master?

pg_start_backup() is run on the master.

The rsync copies the data dir of the standby b/c it is local.

I have tried rsyncing from the master w/ the same results.

 

 

Also once a week I create a database for backup/archive purposes using pg_basebackup

(whole process takes about 13 hours)

These two processes used to be able to coincide until recently.
Recent changes include a major debian upgrade and a minor version of postgres upgrade from 9.3.10.

Now when the report sync occurs during the pg_basebackup (w/ --xlog-method=stream option) the pg_stop_backup() hangs until

the the pg_basebackup has completed (4 hours later).

Do you also have an archive_command, and what is it? Normally, pg_stop_backup() blocks on the archive command - so perhaps you have ended up with a dependency between that one and the base backup command somehow?

The archive command is:

archive_command = 'rsync -a %p postgres@archivedb:/storage/postgres/9.3/main-archive/pg_xlog/%f'

I thought the archive command was working properly while pg_stop_backup was hanging based on the timestamps of the files, but upon closer

inspection using stat I see that the files actually were not copied over until pg_stop_backup stopped hanging.

Actually it appears that the archive_command is not executed the entire time pg_basebackup is running.
pg_basebackup is started about 5 hours before pg_start_backup is executed.

Based on stat it looks like the wal files get written locally but do not get rsynced until pg_basebackup is done.

 

 

A labeled WAL backup file is created when the pg_stop_backup() is first executed and another

is created when the pg_basebackup completes.

While the pg_stop_backup() hangs the following appears in the logs:

2016-06-11 07:50:45 EDT: WARNING:  pg_stop_backup still waiting for all required WAL segments to be archived (7680 seconds elapsed)
2016-06-11 07:50:45 EDT: HINT:  Check that your archive_command is executing properly.  pg_stop_backup can be canceled safely, but the database backup will not be usable without all the WAL segments.

until eventually:

2016-06-11 12:59:07 EDT:LOG:  duration: 26190082.497 ms  statement: SELECT pg_stop_backup()

The archive command appears to work as WAL files are being archived successfully with timestamps that occur while pg_stop_backup is hanging.

-rw------- 1 postgres postgres 314 Jun 11 12:56 000000030000109200000066.00000028.backup
-rw------- 1 postgres postgres 16M Jun 11 12:56 000000030000109300000029
-rw------- 1 postgres postgres 16M Jun 11 12:54 000000030000109300000028
-rw------- 1 postgres postgres 16M Jun 11 12:52 000000030000109300000027

<snip>
-rw------- 1 postgres postgres 16M Jun 11 06:22 0000000300001092000000F1
-rw------- 1 postgres postgres 335 Jun 11 05:42 0000000300001092000000D4.00000028.backup
-rw------- 1 postgres postgres 16M Jun 11 05:42 0000000300001092000000F0

Content of 0000000300001092000000D4.00000028.backup:

START WAL LOCATION: 1092/D4000028 (file 0000000300001092000000D4)
STOP WAL LOCATION: 1092/F008EA10 (file 0000000300001092000000F0)
CHECKPOINT LOCATION: 1092/D4004E08
BACKUP METHOD: pg_start_backup
BACKUP FROM: master
START TIME: 2016-06-11 04:51:04 EDT
LABEL: reporting 2016-06-11 04:51:03.892804-04
STOP TIME: 2016-06-11 05:42:37 EDT

This file shows that the backup took about an hour, doesn't it? So it doesn't look like it was waiting?

Or are you saying the wait happens *after* the .backup file has been dropped in the archives?

The .backup file gets written locally in a timely manner but doesn't get dropped into the archive until after the
pg_stop_backup() stops hanging.

So it appears that pg_basebackup ( perhaps --xlog-method=stream ? ) is causing the archive_command to pause which in turn

causes pg_stop_backup() to hang?

Thanks.

Alex