when set track_commit_timestamp on, database system abort startup

From: 李海龙 <hailong(dot)li(at)qunar(dot)com>
To: PostgreSQL-development <pgsql-hackers(at)postgresql(dot)org>
Subject: when set track_commit_timestamp on, database system abort startup
Date: 2018-09-14 07:27:34
Message-ID: 11224478-a782-203b-1f17-e4797b39bdf0@qunar.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers


HI, Dear pgsql-hackers

The details are as follows:

Environment:

OS: CentOS 6.7 (Final), Linux 3.18.48-11.el6.x86_64 x86_64, 64-bit

PostgreSQL:

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

postgres=# show wal_level ;
wal_level
-----------
replica
(1 row)

When I enable the parameter track_commit_timestamp in postgresql.conf of a Base Backup (making a Base Backup from a standby and the track_commit_timestamp is off on it),

the database system aborted startup.

The log is:

[ 2018-09-14 14:38:30.723 CST 8433 5b9b5766.20f1 1 0]LOG: database system was interrupted while in recovery at log time 2018-09-12 07:00:05 CST
[ 2018-09-14 14:38:30.723 CST 8433 5b9b5766.20f1 2 0]HINT: If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target.
[ 2018-09-14 14:38:30.817 CST 8433 5b9b5766.20f1 3 0]LOG: redo starts at 1C45/6FC0A230
[ 2018-09-14 14:38:31.215 CST 8433 5b9b5766.20f1 4 0]FATAL: could not access status of transaction 3003911820
[ 2018-09-14 14:38:31.215 CST 8433 5b9b5766.20f1 5 0]DETAIL: Could not read from file "pg_commit_ts/6FEE" at offset 557056: Success.
[ 2018-09-14 14:38:31.215 CST 8433 5b9b5766.20f1 6 0]CONTEXT: WAL redo at 1C45/7844DC60 for Transaction/COMMIT: 2018-09-12 07:00:16.629145+08
[ 2018-09-14 14:38:31.228 CST 8431 5b9b5766.20ef 6 0]LOG: startup process (PID 8433) exited with exit code 1
[ 2018-09-14 14:38:31.228 CST 8431 5b9b5766.20ef 7 0]LOG: aborting startup due to startup process failure
[ 2018-09-14 14:38:31.341 CST 8431 5b9b5766.20ef 8 0]LOG: database system is shut down

I have no choice but I enable the parameter track_commit_timestamp off, the database system is starting up successfully!

The log is:

[ 2018-09-14 14:41:38.887 CST 10210 5b9b5822.27e2 1 0]LOG: database system was interrupted while in recovery at 2018-09-14 14:41:21 CST
[ 2018-09-14 14:41:38.887 CST 10210 5b9b5822.27e2 2 0]HINT: This probably means that some data is corrupted and you will have to use the last backup for recovery.
[ 2018-09-14 14:41:38.977 CST 10210 5b9b5822.27e2 3 0]LOG: database system was not properly shut down; automatic recovery in progress
[ 2018-09-14 14:41:38.979 CST 10210 5b9b5822.27e2 4 0]LOG: redo starts at 1C45/6FC0A230
[[unknown] [unknown] [unknown] [local] 2018-09-14 14:41:43.794 CST 10284 5b9b5827.282c 1 0]LOG: connection received: host=[local]
[postgres template1 [unknown] [local] 2018-09-14 14:41:43.794 CST 10284 5b9b5827.282c 2 0]FATAL: the database system is starting up
......
......
[ 2018-09-14 14:47:03.486 CST 10210 5b9b5822.27e2 5 0]LOG: redo done at 1C63/FF683C98
[ 2018-09-14 14:47:03.486 CST 10210 5b9b5822.27e2 6 0]LOG: last completed transaction was at log time 2018-09-12 13:02:56.737147+08
[ 2018-09-14 14:47:03.491 CST 10210 5b9b5822.27e2 7 0]LOG: checkpoint starting: end-of-recovery immediate
[[unknown] [unknown] [unknown] [local] 2018-09-14 14:47:43.940 CST 13383 5b9b598f.3447 1 0]LOG: connection received: host=[local]
[postgres template1 [unknown] [local] 2018-09-14 14:47:43.940 CST 13383 5b9b598f.3447 2 0]FATAL: the database system is starting up
[ 2018-09-14 14:48:06.651 CST 10210 5b9b5822.27e2 8 0]LOG: checkpoint complete: wrote 1871378 buffers (89.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=57.447 s, sync=5.683 s, total=63.160 s; sync files=1366, longest=0.648 s, average=0.004 s; distance=128192471 kB, estimate=128192471 kB
[ 2018-09-14 14:48:09.932 CST 10208 5b9b5822.27e0 6 0]LOG: database system is ready to accept connections
[[unknown] [unknown] [unknown] [local] 2018-09-14 14:48:31.916 CST 13682 5b9b59bf.3572 1 0]LOG: connection received: host=[local]
[postgres template1 [unknown] [local] 2018-09-14 14:48:31.917 CST 13682 5b9b59bf.3572 2 3/1 0]LOG: connection authorized: user=postgres database=template1
[postgres template1 [unknown] [local] 2018-09-14 14:48:31.944 CST 13682 5b9b59bf.3572 3 0]LOG: disconnection: session time: 0:00:00.027 user=postgres database=template1 host=[local]

Has anyone entered this and please help me.

--
Qunar PostgreSQL DBA hailong.li

Attachment Content-Type Size
hailong_li.vcf text/x-vcard 4 bytes

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Michael Paquier 2018-09-14 07:31:47 Re: Loaded footgun open_datasync on Windows
Previous Message Michael Paquier 2018-09-14 07:26:55 Re: Problem while setting the fpw with SIGHUP