Got "FATAL: could not access status of transaction" in PG 11.2

From: Thunder <thunder1(at)126(dot)com>
To: pgsql-hackers(at)lists(dot)postgresql(dot)org
Subject: Got "FATAL: could not access status of transaction" in PG 11.2
Date: 2019-09-03 15:22:14
Message-ID: 417138e.e97e.16cf7b81e3e.Coremail.thunder1@126.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Shutdown postgres server immediately with pg_ctl stop -m immediate command.
When I restart the server got following fatal message:
-------------------------------------------
126690 2019-09-03 14:06:52 UTC XX000 FATAL: could not access status of transaction 389225416
126690 2019-09-03 14:06:52 UTC XX000 DETAIL: Could not read from file "/1-1/kangda/pgdata/pg_xact/0E7F" at offset 245760: Success.
126690 2019-09-03 14:06:52 UTC XX000 CONTEXT: WAL redo at 237/B9FE02A8 for Transaction/COMMIT: 2019-09-03 10:42:06.086823+00
------------------------------------------------
I use pg_waldump to check xlog,and found this transaction was the first transaction after checkpoint.
---------------------------------------------------
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254157, lsn: 237/B9FDFBF0, prev 237/B9FDFBC8, desc: INSERT_LEAF off 97, blkref #0: rel 1663/259019/275985 blk 508
rmgr: Transaction len (rec/tot): 34/ 34, tx: 3892254157, lsn: 237/B9FDFC30, prev 237/B9FDFBF0, desc: COMMIT 2019-09-03 18:42:06.086146 CST
rmgr: Heap len (rec/tot): 245/ 245, tx: 3892254158, lsn: 237/B9FDFC58, prev 237/B9FDFC30, desc: INSERT off 37, blkref #0: rel 1663/259019/275784 blk 5740
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254158, lsn: 237/B9FDFD50, prev 237/B9FDFC58, desc: INSERT_LEAF off 203, blkref #0: rel 1663/259019/275850 blk 585
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254158, lsn: 237/B9FDFD90, prev 237/B9FDFD50, desc: INSERT_LEAF off 215, blkref #0: rel 1663/259019/275869 blk 188
rmgr: Transaction len (rec/tot): 34/ 34, tx: 3892254158, lsn: 237/B9FDFDD0, prev 237/B9FDFD90, desc: COMMIT 2019-09-03 18:42:06.086162 CST
rmgr: Heap len (rec/tot): 245/ 245, tx: 3892254161, lsn: 237/B9FDFDF8, prev 237/B9FDFDD0, desc: INSERT off 11, blkref #0: rel 1663/259019/275898 blk 5763
rmgr: Standby len (rec/tot): 62/ 62, tx: 0, lsn: 237/B9FDFEF0, prev 237/B9FDFDF8, desc: RUNNING_XACTS nextXid 3892254162 latestCompletedXid 3892254158 oldestRunningXid 3892254159; 3 xacts: 3892254160 3892254161 3892254159
rmgr: XLOG len (rec/tot): 106/ 106, tx: 0, lsn: 237/B9FDFF30, prev 237/B9FDFEF0, desc: CHECKPOINT_ONLINE redo 237/B7D65A10; tli 1; prev tli 1; fpw false; xid 0:3892180397; oid 283595; multi 5; offset 9; oldest xid 3451212705 in DB 13287; oldest multi 1 in DB 13286; oldest/newest commit timestamp xid: 0/0; oldest running xid 3892180384; online
rmgr: Heap len (rec/tot): 245/ 245, tx: 3892254159, lsn: 237/B9FDFFA0, prev 237/B9FDFF30, desc: INSERT off 24, blkref #0: rel 1663/259019/275789 blk 5756
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254161, lsn: 237/B9FE00B0, prev 237/B9FDFFA0, desc: INSERT_LEAF off 86, blkref #0: rel 1663/259019/275973 blk 586
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254159, lsn: 237/B9FE00F0, prev 237/B9FE00B0, desc: INSERT_LEAF off 366, blkref #0: rel 1663/259019/275852 blk 585
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254161, lsn: 237/B9FE0130, prev 237/B9FE00F0, desc: INSERT_LEAF off 88, blkref #0: rel 1663/259019/275991 blk 149
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254159, lsn: 237/B9FE0170, prev 237/B9FE0130, desc: INSERT_LEAF off 20, blkref #0: rel 1663/259019/275865 blk 680
rmgr: Heap len (rec/tot): 245/ 245, tx: 3892254160, lsn: 237/B9FE01B0, prev 237/B9FE0170, desc: INSERT off 16, blkref #0: rel 1663/259019/275900 blk 5753
rmgr: Transaction len (rec/tot): 34/ 34, tx: 3892254161, lsn: 237/B9FE02A8, prev 237/B9FE01B0, desc: COMMIT 2019-09-03 18:42:06.086823 CST
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254160, lsn: 237/B9FE02D0, prev 237/B9FE02A8, desc: INSERT_LEAF off 170, blkref #0: rel 1663/259019/275972 blk 585
rmgr: Btree len (rec/tot): 64/ 64, tx: 3892254160, lsn: 237/B9FE0310, prev 237/B9FE02D0, desc: INSERT_LEAF off 146, blkref #0: rel 1663/259019/275989 blk 137
rmgr: Transaction len (rec/tot): 34/ 34, tx: 3892254159, lsn: 237/B9FE0350, prev 237/B9FE0310, desc: COMMIT 2019-09-03 18:42:06.086830 CST
rmgr: Transaction len (rec/tot): 34/ 34, tx: 3892254160, lsn: 237/B9FE0378, prev 237/B9FE0350, desc: COMMIT 2019-09-03 18:42:06.086834 CST
-------------------------------------------------------------------

The call stack is
#0 proc_exit (code=code(at)entry=1) at ipc.c:105
#1 0x00000000009799c7 in errfinish (dummy=<optimized out>) at elog.c:557
#2 0x000000000051a0b0 in SlruReportIOError (ctl=ctl(at)entry=0xe680c0 <ClogCtlData>, pageno=pageno(at)entry=118782, xid=xid(at)entry=3892254161) at slru.c:925
#3 0x000000000051b524 in SimpleLruReadPage (ctl=ctl(at)entry=0xe680c0 <ClogCtlData>, pageno=118782, write_ok=<optimized out>, xid=xid(at)entry=3892254161) at slru.c:459
#4 0x0000000000511ec2 in TransactionIdSetPageStatusInternal (xid=3892254161, nsubxids=0, subxids=0x0, status=1, lsn=0, pageno=<optimized out>) at clog.c:370
#5 0x0000000000512787 in TransactionIdSetPageStatus (all_xact_same_page=true, pageno=118782, lsn=0, status=1, subxids=0x0, nsubxids=0, xid=3892254161) at clog.c:322
#6 TransactionIdSetTreeStatus (xid=xid(at)entry=3892254161, nsubxids=<optimized out>, subxids=0x0, status=status(at)entry=1, lsn=lsn(at)entry=0) at clog.c:194
#7 0x000000000051d41d in TransactionIdCommitTree (xid=xid(at)entry=3892254161, nxids=<optimized out>, xids=<optimized out>) at transam.c:262
#8 0x0000000000521f3f in xact_redo_commit (parsed=parsed(at)entry=0x7fffc2219610, xid=3892254161, lsn=2438366888656, origin_id=<optimized out>) at xact.c:5629
#9 0x0000000000526af3 in xact_redo (record=0x21ed058) at xact.c:5829
#10 0x0000000000537539 in StartupXLOG () at xlog.c:7647
#11 0x00000000007826fb in StartupProcessMain () at startup.c:213
#12 0x0000000000562e95 in AuxiliaryProcessMain (argc=argc(at)entry=2, argv=argv(at)entry=0x7fffc221d8d0) at bootstrap.c:441
#13 0x000000000077e7a4 in StartChildProcess (type=StartupProcess) at postmaster.c:5598
#14 0x00000000007820eb in PostmasterMain (argc=argc(at)entry=3, argv=argv(at)entry=0x21b1cf0) at postmaster.c:1417
#15 0x000000000048787b in main (argc=3, argv=0x21b1cf0) at main.c:228

Is CLOG file flushed before commit log flushed to XLOG file?

Best regards

Ray

Browse pgsql-hackers by date

  From Date Subject
Next Message Fujii Masao 2019-09-03 15:32:03 Re: Fetching timeline during recovery
Previous Message Tom Lane 2019-09-03 15:00:22 Re: block-level incremental backup