WAL-E: Cannot restart postgresql after backup-fetch

Question

This is on Ubuntu 14.04 LTS

EDIT:

WAL-E installed using pip, with secret keys managed by envdir, according to the instructions https://gist.github.com/elithrar/8682235 and https://github.com/wal-e/wal-e#dependencies.

I am trying to restore a database using WAL-E, and everything appears to go well initially, as I have Postgres installed and running, and can easily create or restore a database and access it locally and remotely via pgadmin. Where it goes bad is when I try to perform a restore from an S3 backup using wal-e fetch-backup. It appears to go well up until the point of starting the postgres.

There are a number of errors that come up, appearing to be either missing packages or permissions issues, like the following:

* Starting PostgreSQL 9.3 database server 
    * The PostgreSQL server failed to start. Please check the log output:
    2015-07-11 00:41:11 EDT LOG:  database system was interrupted; last known up at 2015-06-30 05:00:02 EDT
        2015-07-11 00:41:11 EDT LOG:  starting archive recovery
        Traceback (most recent call last):
          File "/usr/local/bin/wal-e", line 5, in <module>
            from pkg_resources import load_entry_point
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3084, in <module>
            @_call_aside
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3070, in _call_aside
            f(*args, **kwargs)
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3097, in _initialize_master_working_set
            working_set = WorkingSet._build_master()
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 651, in _build_master
            ws.require(__requires__)
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 952, in require
            needed = self.resolve(parse_requirements(requirements))
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 847, in resolve
            new_requirements = dist.requires(req.extras)[::-1]
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 2602, in requires
            dm = self._dep_map
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 2803, in _dep_map
            self.__dep_map = self._compute_dependencies()
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 2825, in _compute_dependencies
            for req in self._parsed_pkg_info.get_all('Requires-Dist') or []:
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 2794, in _parsed_pkg_info
            metadata = self.get_metadata(self.PKG_INFO)
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 1617, in get_metadata
            return self._get(self._fn(self.egg_info, name))
          File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 1728, in _get
            with open(path, 'rb') as stream:
        IOError: [Errno 13] Permission denied: '/usr/local/lib/python2.7/dist-packages/six-1.9.0.dist-info/METADATA'
        2015-07-11 00:41:11 EDT LOG:  invalid checkpoint record
        2015-07-11 00:41:11 EDT FATAL:  could not locate required checkpoint record
        2015-07-11 00:41:11 EDT HINT:  If you are not restoring from a backup, try removing the file "/var/lib/postgresql/9.3/main/backup_label".
        2015-07-11 00:41:11 EDT LOG:  startup process (PID 1693) exited with exit code 1
        2015-07-11 00:41:11 EDT LOG:  aborting startup due to startup process failure

I had several of these and was able to resolve them by changing the group and modifying the permissions on the noted files to match others in the directory, but I suspect the problem has more to do with how and/or where these packages were installed. After resolving the above issue, postgres still fails to start up, returning the following:

* Starting PostgreSQL 9.3 database server
* The PostgreSQL server failed to start. Please check the log output:
2015-07-11 00:30:04 EDT LOG:  database system was interrupted; last known up at 2015-06-30 05:00:02 EDT
2015-07-11 00:30:04 EDT LOG:  starting archive recovery
Traceback (most recent call last):
  File "/usr/local/bin/wal-e", line 5, in <module>
    from pkg_resources import load_entry_point
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3084, in <module>
    @_call_aside
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3070, in _call_aside
    f(*args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 3097, in _initialize_master_working_set
    working_set = WorkingSet._build_master()
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 651, in _build_master
    ws.require(__requires__)
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 952, in require
    needed = self.resolve(parse_requirements(requirements))
  File "/usr/local/lib/python2.7/dist-packages/pkg_resources/__init__.py", line 839, in resolve
    raise DistributionNotFound(req, requirers)
pkg_resources.DistributionNotFound: The 'wal-e==0.8.1' distribution was not found and is required by the application
2015-07-11 00:30:04 EDT LOG:  invalid checkpoint record
2015-07-11 00:30:04 EDT FATAL:  could not locate required checkpoint record
2015-07-11 00:30:04 EDT HINT:  If you are not restoring from a backup, try removing the file "/var/lib/postgresql/9.3/main/backup_label".
2015-07-11 00:30:04 EDT LOG:  startup process (PID 1495) exited with exit code 1
2015-07-11 00:30:04 EDT LOG:  aborting startup due to startup process failure

It is complaining about the 'wal-e==0.8.1' distribution was not found..., but it is clearly installed and executable:

ls -l /usr/local/lib/python2.7/dist-packages
total 608
drwxr-sr-x  2 root staff  4096 Jul 10 20:14 argparse-1.3.0.dist-info
-rw-r--r--  1 root staff 88400 Jul 10 20:14 argparse.py
-rw-r--r--  1 root staff 65659 Jul 10 20:14 argparse.pyc
drwxr-sr-x  6 root staff  4096 Jul  9 22:36 azure
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 azure-0.11.1.egg-info
drwxr-sr-x  5 root staff  4096 Jul  9 22:36 babel
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 Babel-1.3.egg-info
drwxr-sr-x 57 root staff  4096 Jul  9 22:36 boto
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 boto-2.38.0.dist-info
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 concurrent
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 dateutil
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 debtcollector
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 debtcollector-0.5.0.dist-info
-rw-r--r--  1 root staff   207 Jul 10 20:10 easy-install.pth
-rw-r--r--  1 root staff   126 Jul 10 20:33 easy_install.py
-rw-r--r--  1 root staff   315 Jul 10 20:33 easy_install.pyc
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 futures-3.0.3.dist-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 gevent
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 gevent-1.0.2.egg-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 greenlet-0.4.7.egg-info
-rwxr-xr-x  1 root staff 82869 Jul  9 22:36 greenlet.so
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 iso8601
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 iso8601-0.1.10.egg-info
drwxr-sr-x 15 root staff  4096 Jul  9 22:36 keystoneclient
drwxr-sr-x  2 root staff  4096 Jul 10 20:33 _markerlib
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 msgpack
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 msgpack_python-0.4.6.egg-info
drwxr-sr-x  5 root staff  4096 Jul  9 22:36 netaddr
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 netaddr-0.7.15.dist-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 netifaces-0.10.4.egg-info
-rwxr-xr-x  1 root staff 58386 Jul  9 22:36 netifaces.so
drwxr-sr-x  4 root staff  4096 Jul  9 22:36 oslo
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 oslo_config
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 oslo.config-1.14.0.dist-info
-rw-r--r--  1 root root    299 Jul  9 22:35 oslo.config-1.14.0-py2.7-nspkg.pth
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 oslo_i18n
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 oslo.i18n-2.1.0.dist-info
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 oslo_serialization
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 oslo.serialization-1.7.0.dist-info
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 oslo_utils
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 oslo.utils-1.8.0.dist-info
-rw-r--r--  1 root root    299 Jul  9 22:35 oslo.utils-1.8.0-py2.7-nspkg.pth
drwxr-sr-x  5 root staff  4096 Jul 10 20:14 pbr
drwxr-sr-x  2 root staff  4096 Jul 10 20:14 pbr-1.3.0.dist-info
drwxr-sr-x  4 root staff  4096 Jul 10 20:10 pip-7.1.0-py2.7.egg
drwxr-sr-x  3 root staff  4096 Jul 10 20:33 pkg_resources
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 python_dateutil-2.4.2.dist-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 python_keystoneclient-1.6.0.dist-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 python_swiftclient-2.4.0.dist-info
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 pytz
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 pytz-2015.4.dist-info
drwxr-sr--  3 root staff  4096 Jul  9 23:25 requests
drwxr-sr--  2 root staff  4096 Jul  9 23:25 requests-2.7.0.dist-info
drwxr-sr-x  3 root staff  4096 Jul 10 20:33 setuptools
drwxr-sr-x  2 root staff  4096 Jul 10 20:33 setuptools-18.0.1.dist-info
drwxr-sr-x  3 root staff  4096 Jul  9 22:36 simplejson
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 simplejson-3.7.3.egg-info
drwxr-sr--  2 root staff  4096 Jul  9 23:26 six-1.9.0.dist-info
-rw-r--r--  1 root root  29664 Jul  9 23:26 six.py
-rw-r--r--  1 root root  29006 Jul  9 23:26 six.pyc
drwxr-sr-x  4 root staff  4096 Jul  9 22:36 stevedore
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 stevedore-1.6.0.dist-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 swiftclient
drwxr-sr-x  7 root staff  4096 Jul  9 22:35 wal_e
drwxr-sr-x  2 root staff  4096 Jul  9 22:35 wal_e-0.8.1.egg-info
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 wrapt
drwxr-sr-x  2 root staff  4096 Jul  9 22:36 wrapt-1.10.5.egg-info

I have done quite a bit of searching, but haven't found anything that helps. Any suggestions or points in the right direction are appreciated.

Additionally, it would be of great interest to solve this to ensure that my primary installation will behave in the event that a restoration is necessary. Backing up is pointless if I can't restore it.

This would be better if asked on dba.stackexchange.com. Best of luck. — Bob Jarvis - Слава Україні, Jul 11 '15 at 22:38
At a guess you've installed WAL-E in some per-user location, rather than site-wide, so it's not finding it when it runs as a different operating system user. How *exactly* did you install it? — Craig Ringer, Jul 12 '15 at 04:58
WAL-E installed via pip: `sudo pip install wal-e` as seen https://gist.github.com/elithrar/8682235 and https://github.com/wal-e/wal-e#dependencies — zugzwang, Jul 12 '15 at 15:23

score 0 · Accepted Answer · answered Jul 13 '15 at 16:59

I am not entirely sure what resolved the The 'wal-e==0.8.1' distribution was not found errro, but on rebooting I never saw that again.

Aside from that, fixing this was rather straightforward.

The executable bit on a number of python distributions was not set.

Chowning these fixed the error:

      chmod o+x /usr/local/lib/python2.7/dist-packages/requests-2.7.0.dist-info/
      chmod o+x /usr/local/lib/python2.7/dist-packages/requests
...

score 0 · Answer 2 · answered Jul 15 '15 at 06:43

Reason backup_label is not created properly

Run the below command in your Master

su postgres

psql -c "select pg_start_backup('initial_backup');"

rsync -cva --inplace --exclude=pg_xlog /var/lib/postgresql/9.1/main/ slave_IP_address:/var/lib/postgresql/9.1/main/

psql -c "select pg_stop_backup();"
cd /var/lib/postgresql/9.1/main

create file name recovery.conf add the below lines

standby_mode = 'on' primary_conninfo = 'host=master_IP_address port=5432 user=rep password=yourpassword' trigger_file = '/tmp/postgresql.trigger.5432'

service postgresql restart

Thank you for the feedback, but I don't think this is the problem since I was able to resolve my issue through permissions management. I also have the master happily generating nightly base-backups, and have had no issues on that machine so far. I upvoted your answer, but I don't yet have the rep for it to stick. — zugzwang, Jul 16 '15 at 22:10

WAL-E: Cannot restart postgresql after backup-fetch

2 Answers2