Обсуждение: [NOVICE] Issues shutting down PostgreSQL 10 cleanly

Поиск
Список
Период
Сортировка

[NOVICE] Issues shutting down PostgreSQL 10 cleanly

От
Stephen Froehlich
Дата:

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

 

Stephen Froehlich
Sr. Strategist, CableLabs®


s.froehlich@cablelabs.com

Tel: +1 (303) 661-3708

 

Re: [NOVICE] Issues shutting down PostgreSQL 10 cleanly

От
Laurenz Albe
Дата:
Stephen Froehlich wrote:
> 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:
thisis 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
code1
 
> 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:08MDT
 
> 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

What happens if you run /etc/init.d/postgresql stop?

Clean shutdown? Any processes left running?

I would examine /etc/init.d/postgresql and see if it does evil things
like porcibly remove the postmaster.pid file.

Yours,
Laurenz Albe


-- 
Sent via pgsql-novice mailing list (pgsql-novice@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-novice

Re: [NOVICE] Issues shutting down PostgreSQL 10 cleanly

От
Simon Riggs
Дата:
On 23 October 2017 at 15:23, Stephen Froehlich
<s.froehlich@cablelabs.com> wrote:
> 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?

The time to shutdown will be longer than normal with those settings.

--
Simon Riggs                http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services


--
Sent via pgsql-novice mailing list (pgsql-novice@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-novice

Re: [NOVICE] Issues shutting down PostgreSQL 10 cleanly

От
Stephen Froehlich
Дата:
Hi Laurenz,

/etc/init.d/postgresql stop prompts the same condition.

Simon - I get that ... 

Apparently the solution is to run a checkpoint first and then shutdown?
http://rhaas.blogspot.com/2015/03/postgresql-shutdown.html

I'll try this likely tomorrow and let you know.


--Stephen

-----Original Message-----
From: Laurenz Albe [mailto:laurenz.albe@cybertec.at] 
Sent: Tuesday, October 24, 2017 12:20 AM
To: Stephen Froehlich <s.froehlich@cablelabs.com>; pgsql-novice@postgresql.org
Subject: Re: [NOVICE] Issues shutting down PostgreSQL 10 cleanly

CableLabs WARNING: The sender of this email could not be validated and may not match the person in the "From" field.

Stephen Froehlich wrote:
> 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:
thisis 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

What happens if you run /etc/init.d/postgresql stop?

Clean shutdown? Any processes left running?

I would examine /etc/init.d/postgresql and see if it does evil things like porcibly remove the postmaster.pid file.

Yours,
Laurenz Albe

--
Sent via pgsql-novice mailing list (pgsql-novice@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-novice