Re: 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/