Thread: [GENERAL] Issues shutting down PostgreSQL 10 cleanly

I am in the midst of heavy, large write operations on a new database this is currently around 23 billion lines.

My max_wal_size is 256 GB and my checkpoint_timeout is 12 hours. (Smaller values were hindering the writes.) Note: this is on Ubuntu 16.04 LTS.

I am having trouble shutting down postgres cleanly – how can I fix that?

A “/etc/init.d/postgresql restart” command gave the following log entries:

2017-10-20 09:17:55.069 MDT [16388] LOG:  received fast shutdown request

2017-10-20 09:17:55.069 MDT [16388] LOG:  aborting any active transactions

2017-10-20 09:17:55.069 MDT [20336] FATAL:  terminating autovacuum process due to administrator command

2017-10-20 09:17:55.069 MDT [20540] FATAL:  terminating autovacuum process due to administrator command

2017-10-20 09:17:55.069 MDT [20132] FATAL:  terminating autovacuum process due to administrator command

2017-10-20 09:17:55.070 MDT [1486] sfroehlich@mediacom_df_vd FATAL:  terminating connection due to administrator command

2017-10-20 09:17:55.070 MDT [1488] sfroehlich@mediacom_df_vd FATAL:  terminating connection due to administrator command

2017-10-20 09:17:55.070 MDT [1487] sfroehlich@mediacom_df_vd FATAL:  terminating connection due to administrator command

2017-10-20 09:17:55.070 MDT [1489] sfroehlich@mediacom_df_vd FATAL:  terminating connection due to administrator command

2017-10-20 09:17:55.070 MDT [1485] sfroehlich@mediacom_df_vd FATAL:  terminating connection due to administrator command

2017-10-20 09:17:55.074 MDT [16388] LOG:  worker process: logical replication launcher (PID 16400) exited with exit code 1

2017-10-20 09:19:08.363 MDT [16395] LOG:  shutting down

2017-10-20 09:20:29.559 MDT [32352] LOG:  listening on IPv4 address "0.0.0.0", port 5432

2017-10-20 09:20:29.559 MDT [32352] LOG:  listening on IPv6 address "::", port 5432

2017-10-20 09:20:29.560 MDT [32352] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"

2017-10-20 09:20:57.956 MDT [32454] LOG:  database system shutdown was interrupted; last known up at 2017-10-20 09:19:08 MDT

2017-10-20 09:21:03.598 MDT [32454] LOG:  database system was not properly shut down; automatic recovery in progress

2017-10-20 09:21:03.646 MDT [32454] LOG:  redo starts at 972/DB0B0838

pg_ctl: server did not start in time

2017-10-20 09:21:29.645 MDT [32352] LOG:  received smart shutdown request

2017-10-20 09:21:29.735 MDT [32558] LOG:  shutting down

2017-10-20 09:21:30.019 MDT [32352] LOG:  database system is shut down

Then single-user-mode restore gave the following output.

postgres@pisa:/usr/lib/postgresql/10/bin$ ./postgres --single -D /etc/postgresql/10/main/ -P -d 1

2017-10-20 09:24:59.669 MDT [33361] DEBUG:  mmap(35192307712) with MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory

2017-10-20 09:25:00.077 MDT [33361] LOG:  database system was shut down in recovery at 2017-10-20 09:21:29 MDT

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  checkpoint record is at 97F/4F7E7168

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  redo record is at 972/DB0B0838; shutdown FALSE

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  next transaction ID: 0:1194772; next OID: 966656

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  next MultiXactId: 1; next MultiXactOffset: 0

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  oldest unfrozen transaction ID: 548, in database 1

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  oldest MultiXactId: 1, in database 1

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  commit timestamp Xid oldest/newest: 0/0

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  transaction ID wrap limit is 2147484195, limited by database with OID 1

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  MultiXactId wrap limit is 2147483648, limited by database with OID 1

2017-10-20 09:25:00.077 MDT [33361] DEBUG:  starting up replication slots

2017-10-20 09:25:00.077 MDT [33361] LOG:  database system was not properly shut down; automatic recovery in progress

2017-10-20 09:25:00.078 MDT [33361] DEBUG:  resetting unlogged relations: cleanup 1 init 0

2017-10-20 09:25:00.125 MDT [33361] LOG:  redo starts at 972/DB0B0838

2017-10-20 10:35:05.773 MDT [33361] LOG:  invalid record length at 97F/4F7E71D8: wanted 24, got 0

2017-10-20 10:35:05.773 MDT [33361] LOG:  redo done at 97F/4F7E7168

2017-10-20 10:35:05.773 MDT [33361] LOG:  last completed transaction was at log time 2017-10-20 09:17:46.905639-06

2017-10-20 10:35:05.774 MDT [33361] DEBUG:  resetting unlogged relations: cleanup 0 init 1

2017-10-20 10:35:06.350 MDT [33361] DEBUG:  performing replication slot checkpoint

2017-10-20 11:25:10.991 MDT [33361] DEBUG:  MultiXactId wrap limit is 2147483648, limited by database with OID 1

2017-10-20 11:25:10.991 MDT [33361] DEBUG:  MultiXact member stop limit is now 4294914944 based on MultiXact 1

2017-10-20 11:25:11.035 MDT [33361] DEBUG:  loaded library "pgcrypto"

PostgreSQL stand-alone backend 10.0

backend> [Ctrl+D]

2017-10-20 11:30:31.268 MDT [33361] NOTICE:  shutting down

2017-10-20 11:30:31.270 MDT [33361] DEBUG:  performing replication slot checkpoint

2017-10-20 11:31:40.767 MDT [33361] NOTICE:  database system is shut down

Thanks in advance for your help …

--Stephen