Permission Denied Error on pg_xlog/RECOVERYXLOG file

Hi Folks,

We reported a bug last month (#14119) related to receiving a permission denied error on the pg_xlog/RECOVERYXLOG file when performing a database recovery (PostgreSQL versions 9.2.16 and 9.2.17). The bug report was for version 9.2.16 but we also are having the same problem with 9.2.17. We were just curious if anyone else running 9.2.16 or 9.2.17 had encountered this issue.

The link to the bug report is below, but much of the information is included here as well.

When performing a vanilla database restore using either the 9.2.16 or 9.2.17 executables (i.e. just restoring the database files from a 'tar' backup and reading the WAL files created during the 'tar' backup - no specific PIT given in recovery.conf) the database server will abort with a permission denied error on the pg_xlog/RECOVERYXLOG file. The error occurred restoring both backups that were made under the current version (9.2.16 and 9.2.17) as well as backups made under prior versions (9.2.15 at least). The exact same restore process/backup files can be used to successfully restore the database using the 9.2.15 executables, but fail when using either 9.2.16 or 9.2.17 with the permission denied error.

ENVIRONMENT: PostgreSQL 9.2.16

[postgres-pt(at)postXX pg_xlog]$ psql --version
psql (PostgreSQL) 9.2.16

[postgres-pt(at)postXX pg_xlog]$ psql
psql (9.2.16)
Type "help" for help.

admin_db=# select version();
version
----------------------------------------------------------------------------------------------------------------
PostgreSQL 9.2.16 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.4.7
20120313 (Red Hat 4.4.7-16), 64-bit
(1 row)

OPERATING SYSTEM INFORMATION:

The database server is running on a Redhat Linux host (Red Hat Enterprise Linux Server release 6.8 (Santiago)) -

[postgres-pt(at)postXX pg_xlog]$ uname -a
Linux 2.6.32-573.22.1.el6.x86_64 #1 SMP Thu Mar 17 03:23:39 EDT 2016 x86_64 x86_64 x86_64 GNU/Linux

The Postgres executables were downloaded/installed using rpm/yum (yum update postgresql92-server) and not compiled locally (same download/install process as prior versions) - no additional modules/no modifications have been made.

STEPS TAKEN TO PRODUCE ERROR:

The restores being performed are not to a specific point in time (i.e. restore the database as of 4/18/16 09:59:17); the restores are just loading the database as of the completion of the last full backup.

Perform a database backup:

select pg_start_backup('backup_2016_04_19');

tar and compress the tablespace directories (2 tablespace directories in this case) and the cluster directory
save any WAL files created during the backup

select pg_stop_backup();

Restore the database:

Remove tablespace directories
Remove cluster directory
Uncompress/extract the tablespace directories
Uncompress/extract the cluster directory
Remove files from pg_xlog directory
Create a recovery.conf file that points to the directory with the WAL archive files created during the backup

restart the server using the 9.2.16 executables

pg_ctl -D /pgdata/pgsrv_cluster_data/postXX_rest_92 start

Message from database error log:

2016-04-27 17:02:05 EDT 572128cd.1811 [1-1] user=,db=,remote= LOG: 00000:
database system was interrupted; last known up at 2016-04-19 14:18:03 EDT
2016-04-27 17:02:05 EDT 572128cd.1811 [2-1] user=,db=,remote= LOCATION:
StartupXLOG, xlog.c:6372
2016-04-27 17:02:05 EDT 572128cd.1811 [3-1] user=,db=,remote= LOG: 00000:
starting archive recovery
2016-04-27 17:02:05 EDT 572128cd.1811 [4-1] user=,db=,remote= LOCATION:
StartupXLOG, xlog.c:6465
2016-04-27 17:02:06 EDT 572128cd.1811 [5-1] user=,db=,remote= LOG: 00000:
restored log file "0000000100000006000000FE" from archive
2016-04-27 17:02:06 EDT 572128cd.1811 [6-1] user=,db=,remote= LOCATION:
RestoreArchivedFile, xlog.c:3267
2016-04-27 17:02:06 EDT 572128cd.1811 [7-1] user=,db=,remote= FATAL: 42501:
could not open file "pg_xlog/RECOVERYXLOG": Permission denied
2016-04-27 17:02:06 EDT 572128cd.1811 [8-1] user=,db=,remote= LOCATION:
fsync_fname_ext, fd.c:2654
2016-04-27 17:02:06 EDT 572128cc.180f [3-1] user=,db=,remote= LOG: 00000:
startup process (PID 6161) exited with exit code 1
2016-04-27 17:02:06 EDT 572128cc.180f [4-1] user=,db=,remote= LOCATION:
LogChildExit, postmaster.c:3008
2016-04-27 17:02:06 EDT 572128cc.180f [5-1] user=,db=,remote= LOG: 00000:
aborting startup due to startup process failure
2016-04-27 17:02:06 EDT 572128cc.180f [6-1] user=,db=,remote= LOCATION:
reaper, postmaster.c:2461

Thanks,
Jeff Marshall

Link to bug report: http://www.postgresql.org/message-id/20160428132828.19110.9264@wrigleys.postgresql.org