[Pkg-postgresql-public] Bug#916299: postgresql-11: starts with error after upgrade from stretch to buster

Andreas Beckmann anbe at debian.org
Wed Dec 12 20:20:14 GMT 2018 

Package: postgresql-11
Version: 11.1-1
Severity: important
User: debian-qa at lists.debian.org
Usertags: piuparts

Hi,

during a test with piuparts I noticed your package fails to upgrade from
'stretch'.
It installed fine in 'stretch', then the upgrade to 'buster' fails.

>From the attached log (scroll to the bottom...):

  Setting up postgresql-11 (11.1-1+b2) ...
  Creating new PostgreSQL cluster 11/main ...
  /usr/lib/postgresql/11/bin/initdb -D /var/lib/postgresql/11/main --auth-local peer --auth-host md5
  The files belonging to this database system will be owned by user "postgres".
  This user must also own the server process.
  
  The database cluster will be initialized with locale "C.UTF-8".
  The default database encoding has accordingly been set to "UTF8".
  The default text search configuration will be set to "english".
  
  Data page checksums are disabled.
  
  fixing permissions on existing directory /var/lib/postgresql/11/main ... ok
  creating subdirectories ... ok
  selecting default max_connections ... 100
  selecting default shared_buffers ... 128MB
  selecting dynamic shared memory implementation ... posix
  creating configuration files ... ok
  running bootstrap script ... ok
  performing post-bootstrap initialization ... ok
  syncing data to disk ... ok
  
  Success. You can now start the database server using:
  
      /usr/lib/postgresql/11/bin/pg_ctl -D /var/lib/postgresql/11/main -l logfile start
  
  Ver Cluster Port Status Owner    Data directory              Log file
  [ESC][31m11  main    5432 down   postgres /var/lib/postgresql/11/main /var/log/postgresql/postgresql-11-main.log[ESC][0m
  update-alternatives: using /usr/share/postgresql/11/man/man1/postmaster.1.gz to provide /usr/share/man/man1/postmaster.1.gz (postmaster.1.gz) in auto mode
  invoke-rc.d: could not determine current runlevel
  Starting PostgreSQL 11 database server: mainThe PostgreSQL server failed to start. Please check the log output: 2018-12-12 17:39:34.198 UTC [17806] LOG: listening on IPv6 address "::1", port 5432 2018-12-12 17:39:34.198 UTC [17806] LOG: listening on IPv4 address "127.0.0.1", port 5432 2018-12-12 17:39:34.198 UTC [17806] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" 2018-12-12 17:39:34.204 UTC [17833] LOG: database system was shut down at 2018-12-12 17:39:33 UTC 2018-12-12 17:39:34.207 UTC [17806] LOG: database system is ready to accept connections 2018-12-12 17:39:34.792 UTC [19057] [unknown]@[unknown] LOG: incomplete startup packet ... failed!
   failed!
  invoke-rc.d: initscript postgresql, action "start" failed.
  dpkg: error processing package postgresql-11 (--configure):
   subprocess installed post-installation script returned error exit status 1


To summarize what the piuparts test does (should do) for postgresql:

- start with a minimal stretch chroot, allow starting the postgresql service
- install postgresql
- switch apt sources to buster
- install postgresql/buster
*** it failed here to start the -11 server ***
therefore the following actions were not performed
- perform the pg_upgradecluster dance
- perform the --dist-upgrade

The intention of upgrading postgresql early is to ensure the service is running 
throughout the dist-upgrade for the tested packages to be able to perform
their database upgrades.
Packages that only recommend the postgresql package (because they could also 
work with a remote database server) get postgresql installed into the chroot
by piuparts before the actual test starts. During dist-upgrade there is no
dependency ensuring that postgresql is running  while the upgraded database
using package gets configured, so upgrading postgresql first avoids any downtime
during the dist-upgrade.

This scheme has been working quite well for some time already, but we are always
open for improvements.


If I enter the chroot directly after the failure, I find the following state:

# invoke-rc.d postgresql status
invoke-rc.d: could not determine current runlevel
9.6/main (port 5432): online
11/main (port 5433): online

# invoke-rc.d postgresql stop
invoke-rc.d: could not determine current runlevel
[ ok ] Stopping PostgreSQL 11 database server: main.
[ ok ] Stopping PostgreSQL 9.6 database server: main.

# invoke-rc.d postgresql start
invoke-rc.d: could not determine current runlevel
[....] Starting PostgreSQL 11 database server: main[....] The PostgreSQL server failed to start. Please check the log output: 2018-12-12 20:08:03.529 UTC [892] LOG: listening on IPv6 address "::1", port 5433 2018-12-12 20:08:03.529 UTC [892] LOG: listening on IPv4 address "127.0.0.1", port 5433 2018-12-12 20:08:03.529 UTC [892] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433" 2018-12-12 20:08:03.544 UTC [898] LOG: database system was shut down at 2018-12-12 20:07:51 UTC 2018-12-12 20:08:03.548 UTC [892] LOG: database system is ready to accept connections 2018-12-12 20:08:04.126 UTC [986] [unknown]@[unknown] LOG:[FAILmplete startup packet ... failed!
 failed!
[ ok ] Starting PostgreSQL 9.6 database server: main.
invoke-rc.d: initscript postgresql, action "start" failed.

# invoke-rc.d postgresql status
invoke-rc.d: could not determine current runlevel
9.6/main (port 5432): online
11/main (port 5433): online

# pg_lsclusters -h
9.6 main 5432 online postgres /var/lib/postgresql/9.6/main /var/log/postgresql/postgresql-9.6-main.log
11  main 5433 online postgres /var/lib/postgresql/11/main  /var/log/postgresql/postgresql-11-main.log

# invoke-rc.d postgresql stop
invoke-rc.d: could not determine current runlevel
[ ok ] Stopping PostgreSQL 11 database server: main.
[ ok ] Stopping PostgreSQL 9.6 database server: main.

# pg_lsclusters -h
9.6 main 5432 down postgres /var/lib/postgresql/9.6/main /var/log/postgresql/postgresql-9.6-main.log
11  main 5433 down postgres /var/lib/postgresql/11/main  /var/log/postgresql/postgresql-11-main.log

# pg_ctlcluster 9.6 main start ; echo $?
0

# pg_ctlcluster 11 main start ; echo $?
The PostgreSQL server failed to start. Please check the log output:
2018-12-12 20:09:45.692 UTC [30034] LOG:  listening on IPv6 address "::1", port 5433
2018-12-12 20:09:45.692 UTC [30034] LOG:  listening on IPv4 address "127.0.0.1", port 5433
2018-12-12 20:09:45.693 UTC [30034] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5433"
2018-12-12 20:09:45.701 UTC [30035] LOG:  database system was shut down at 2018-12-12 20:09:17 UTC
2018-12-12 20:09:45.705 UTC [30034] LOG:  database system is ready to accept connections
2018-12-12 20:09:46.286 UTC [30224] [unknown]@[unknown] LOG:  incomplete startup packet
1

# pg_lsclusters -h
9.6 main 5432 online postgres /var/lib/postgresql/9.6/main /var/log/postgresql/postgresql-9.6-main.log
11  main 5433 online postgres /var/lib/postgresql/11/main  /var/log/postgresql/postgresql-11-main.log


So, despite of throwing "The PostgreSQL server failed to start." the server is running.



cheers,

Andreas

PS: I've never run a postgresql server in a production environment,
so I'm lacking all the details how to handle postgresql properly.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: postgresql_11+197.log.gz
Type: application/gzip
Size: 30784 bytes
Desc: not available
URL: <http://alioth-lists.debian.net/pipermail/pkg-postgresql-public/attachments/20181212/49aca69b/attachment-0001.gz>

More information about the pkg-postgresql-public mailing list