Re: pg_basebackup, requested WAL has already been removed

Its definitely not a bug.  You need to set/increase wal_keep_segments
to a value that ensures that they aren't recycled faster than the time
required to complete the base backup (plus some buffer).

On Fri, May 10, 2013 at 9:48 AM, Sergey Koposov <koposov@ast.cam.ac.uk> wrote:
> Hi,
>
> I've recently started to use pg_basebackup --xlog-method=stream to backup my
> multi-Tb database.
> Before I did the backup when there was not much activity in the DB and it
> went perfectly fine, but today, I've started the backup and it failed twice
> almost at the same time as the
> CREATE INDEX  (and another time CLUSTER) commands were finished.
>
> Here:
>
> postgres@cappc118:/mnt/backup/wsdb_130510$ pg_basebackup
> --xlog-method=stream --progress --verbose --pg
> transaction log start point: 23AE/BD003E70
> pg_basebackup: starting background WAL receiver
> pg_basebackup: unexpected termination of replication stream: FATAL:
> requested WAL segment 00000001000023B1000000FE has already been removed
> 4819820/16816887078 kB (4%), 0/1 tablespace
> (/mnt/backup/wsdb_130510/base/1)
>
> And the logs from around that time contained:
>
> some_user:wsdb:2013-05-10 14:35:41 BST:10587LOG:  duration: 40128.163 ms
> statement: CREATE INDEX usno_cle
> an_q3c_idx ON usno_clean (q3c_ang2ipix(ra,dec));
> ::2013-05-10 14:35:43 BST:25529LOG:  checkpoints are occurring too
> frequently (8 seconds apart)
> ::2013-05-10 14:35:43 BST:25529HINT:  Consider increasing the configuration
> parameter "checkpoint_segmen
> ts".
> ::2013-05-10 14:35:51 BST:25529LOG:  checkpoints are occurring too
> frequently (8 seconds apart)
> ::2013-05-10 14:35:51 BST:25529HINT:  Consider increasing the configuration
> parameter "checkpoint_segmen
> ts".
> postgres:[unknown]:2013-05-10 14:35:55 BST:8177FATAL:  requested WAL segment
> 00000001000023B1000000FE has already been removed
> some_user:wsdb:2013-05-10 14:36:59 BST:10599LOG:  duration: 78378.194 ms
> statement: CLUSTER usno_clean_q3c_idx ON usno_clean;
>
> One the previous occasion when it happened the CREATE INDEX() was being
> executed:
>
> some_user:wsdb:2013-05-10 09:17:20 BST:3300LOG:  duration: 67.680 ms
> statement: SELECT name FROM  (SELECT pg_catalog.lower(name) AS name FROM
> pg_catalog.pg_settings   UNION ALL SELECT 'session authorization'   UNION
> ALL SELECT 'all') ss  WHERE substring(name,1,4)='rand'
>         LIMIT 1000
> ::2013-05-10 09:22:47 BST:25529LOG:  checkpoints are occurring too
> frequently (18 seconds apart)
> ::2013-05-10 09:22:47 BST:25529HINT:  Consider increasing the configuration
> parameter "checkpoint_segments".
> postgres:[unknown]:2013-05-10 09:22:49 BST:27659FATAL:  requested WAL
> segment 000000010000239900000040 has already been removed
> some_user:wsdb:2013-05-10 09:22:57 BST:3236LOG:  duration: 542955.262 ms
> statement: CREATE INDEX xmatch_temp_usnoid_idx ON xmatch_temp (usno_id);
>
> The .configuration
> PG 9.2.4, Debian 7.0, amd64
>
> shared_buffers = 10GB
> work_mem = 1GB
> maintenance_work_mem = 1GB
> effective_io_concurrency = 5
> synchronous_commit = off
> checkpoint_segments = 32
> max_wal_senders = 2
> effective_cache_size = 30GB
> autovacuum_max_workers = 3
> wal_level=archive
> archive_mode = off
>
> Does it look like a bug or am I missing something ?
>
> Thanks,
>         Sergey
>
>
> --
> Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-general



--
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
L. Friedman                                    netllama@gmail.com
LlamaLand                       https://netllama.linux-sxs.org