Re: Postgres base Backup fails to recover all logs fails from archive

Hi

Thanks for your help.

The problem is that it stops to restore the log files after reading log file 0000000100000023000000F7.

The recovery does not continue to read log file 0000000100000023000000F8 and the rest of the log files.

I don't under stand why it stops to read the rest of the log files.

Lars
________________________________________
Fra: Magnus Hagander [magnus(at)hagander(dot)net]
Sendt: 5. januar 2013 22:45
Til: Lars Aksel Opsahl
Kopi: pgsql-admin(at)postgresql(dot)org
Emne: Re: [ADMIN] Postgres base Backup fails to recover all logs fails from archive

On Sat, Jan 5, 2013 at 10:30 PM, Lars Aksel Opsahl
<lop(at)skogoglandskap(dot)no> wrote:
> Hi
>
>
> This is postgreSQL 9.2.1
>
>
> By accident I was running the the following command
>
> «delete from org_oks.oks_kartobjekt_flate where id = 53»
>
> on the wrong database.
>
>
> - I first picked up last basebackup from the backup server. The base backup was from 22/11 and It was made made by using «24.3.3. Making a Base Backup Using the Low Level API» with SELECT pg_start_backup('label'); and then a file system backup and then SELECT pg_stop_backup();
>
>
> The row I deleted was added after the base backup was created.
>
> - Her is the cat from 0000000100000023000000F4.00000020.backup
>
> START WAL LOCATION: 23/F4000020 (file 0000000100000023000000F4)
>
> STOP WAL LOCATION: 23/F47303F0 (file 0000000100000023000000F4)
>
> CHECKPOINT LOCATION: 23/F4000020
>
> BACKUP METHOD: pg_start_backup
>
> BACKUP FROM: master
>
> START TIME: 2012-11-22 09:57:03 CET
>
> LABEL: /backup/db01/base_backup_2012_11_22
>
> STOP TIME: 2012-11-22 10:38:44 CET
>
> - I create the recovery.conf with the following content (I have also tested without recovery_target_time but it's the same behavior)
>
> restore_command ='cp /data01/new_archive_files/%f %p'
>
> recovery_target_time = '2013-01-04 04:00:00'
>
> - Here is the log from startup
>
> LOG: database system was interrupted; last known up at 2012-11-22 10:22:36 CET
>
> LOG: starting archive recovery
>
> LOG: restored log file "0000000100000023000000F4" from archive
>
> LOG: redo starts at 23/F4000080
>
> LOG: consistent recovery state reached at 23/F5000000
>
> LOG: restored log file "0000000100000023000000F5" from archive
>
> LOG: restored log file "0000000100000023000000F6" from archive
>
> LOG: restored log file "0000000100000023000000F7" from archive
>
> LOG: contrecord is requested by 23/F7000020
>
> LOG: redo done at 23/F6000080
>
> LOG: restored log file "0000000100000023000000F6" from archive
>
> cp: cannot stat `/data01/new_archive_files/00000002.history': No such file or directory
>
> LOG: selected new timeline ID: 2
>
> cp: cannot stat `/data01/new_archive_files/00000001.history': No such file or directory
>
> LOG: archive recovery complete
>
> LOG: database system is ready to accept connections
>
> LOG: autovacuum launcher started
>
>
> - Here is the list some the archive files.
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 07:11 000000010000002400000008
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 07:10 000000010000002400000007
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 07:00 000000010000002400000006
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:50 000000010000002400000005
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:45 000000010000002400000004
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:40 000000010000002400000003
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:32 000000010000002400000002
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:26 000000010000002400000001
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:16 000000010000002400000000
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:08 0000000100000023000000FE
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 06:02 0000000100000023000000FD
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:57 0000000100000023000000FC
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:39 0000000100000023000000FB
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:32 0000000100000023000000FA
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:31 0000000100000023000000F9
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:31 0000000100000023000000F8
>
> -rwx------ 1 postgres postgres 16777216 Nov 24 05:27 0000000100000023000000F7
>
> -rwx------ 1 postgres postgres 16777216 Nov 22 12:37 0000000100000023000000F6
>
> -rwx------ 1 postgres postgres 16777216 Nov 22 12:37 0000000100000023000000F5
>
> -rwx------ 1 postgres postgres 16777216 Nov 22 10:38 0000000100000023000000F4
>
> -rwx------ 1 postgres postgres 325 Nov 22 10:38 0000000100000023000000F4.00000020.backup
>
>
> I have two questions
>
> 1. Can anybody see what the problem is here and what I am doing wrong ? (I have done this many times before without any problems.)

What actually went wrong? Because the log looks like a perfectly
normal restore? (Though you should really add timestamps to your log)

> 2. Is it possible to extract sql insert's from the archive files abouve and in that way find the content of the row I deleted ? (The table name oks_kartobjekt_flate only occurs in about 10 archive files)

No, the archive files only contain the binary changes to the disk
blocks, not the SQL statements or data.

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/