pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  

help / color / mirror / Atom feed
From: Alexander Lakhin <exclusion@gmail.com>
To: Tomas Vondra <tomas.vondra@enterprisedb.com>
To: Amit Kapila <amit.kapila16@gmail.com>
To: Masahiko Sawada <sawada.mshk@gmail.com>
Cc: pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: TRAP: FailedAssertion("prev_first_lsn < cur_txn->first_lsn", File: "reorderbuffer.c", Line: 927, PID: 568639)
Date: Tue, 6 Jun 2023 15:00:00 +0300
Message-ID: <1f860e40-9f95-f0f8-ff4b-4b780f9151ad@gmail.com> (raw)
In-Reply-To: <99b45770-e3d8-4522-ea52-f4509931c65b@enterprisedb.com>
References: <a89b46b6-0239-2fd5-71a9-b19b1f7a7145@enterprisedb.com>
	<CAA4eK1+u3Y_X8VCW+iFyTsqXqAkFYWMS=-VX7Tt1C_D_FOr9Qg@mail.gmail.com>
	<CAD21AoAE3j=4SgcY3gLZWwpW+OYV=fumhjeEQmb66AvV27-rrQ@mail.gmail.com>
	<CAA4eK1KOAKHCj+fe8-etZ4GBokA4JsqTH=8cYK4CygEzZbJzbA@mail.gmail.com>
	<CAD21AoBmrum63r5anV+Rxo2MyvxehYioRvkKqvENdYzMvE8_7w@mail.gmail.com>
	<CAA4eK1+K5zbf6euH7ei9eX+A8G5122hjJC3CgtJDdrO16GmDvg@mail.gmail.com>
	<CAD21AoAspaKr=iOO+_Vuju8Gu1ynksnT9ZjVe1CQFQvB3kNrCA@mail.gmail.com>
	<CAD21AoA3Q+2VYbmsBK-HSa2Ns4UTMYiQjWMZXum53ZL9q+ZWqA@mail.gmail.com>
	<CAD21AoCMkJ9YAv0xXah19+he5x6ptva07M+eB0qReS_10Wfqfg@mail.gmail.com>
	<CAA4eK1Jsd2JrOzosKL0MoLsSTLCKAP0AiK2924tiRsv4ftnVLA@mail.gmail.com>
	<CAD21AoCf1Q+2feZ8u7JhHfOrcV0FX+8uRPZJA2chyTsYq-g0fA@mail.gmail.com>
	<CAA4eK1Lx=g09z2k9Teq9ca1eRzfpfxJwFdjyHNwgEKv69KWhrQ@mail.gmail.com>
	<f158d9ca-2057-2836-a522-0b1278be5a53@gmail.com>
	<99b45770-e3d8-4522-ea52-f4509931c65b@enterprisedb.com>

Hello Tomas,

06.06.2023 12:56, Tomas Vondra wrote:
> On 6/6/23 11:00, Alexander Lakhin wrote:
>> Hello,
>> ...> With the debug logging added inside AssertTXNLsnOrder() I see:
>> ctx->snapshot_builder->start_decoding_at: 209807224,
>> ctx->reader->EndRecPtr: 210043072,
>> SnapBuildXactNeedsSkip(ctx->snapshot_builder, ctx->reader->EndRecPtr): 0
>> and inside the loop:
>> cur_txn->first_lsn: 209792872
>> cur_txn->first_lsn: 209975744
>> cur_txn->first_lsn: 210043008
>> cur_txn->first_lsn: 210043008
>> and it triggers the Assert.
>>
> So what's the prev_first_lsn value for these first_lsn values? How does
> it change over time? Did you try looking at the pg_waldump for these
> positions?

With more logging I've got (for another run):
ReorderBufferTXNByXid| xid: 3397, lsn: c1fbc80

ctx->snapshot_builder->start_decoding_at: c1f2cc0, ctx->reader->EndRecPtr: c1fbcc0, 
SnapBuildXactNeedsSkip(ctx->snapshot_builder, ctx->reader->EndRecPtr): 0
prev_first_lsn: 0, cur_txn->first_lsn: c1fbc80
prev_first_lsn: c1fbc80, cur_txn->first_lsn: c1fbc80
TRAP: failed Assert("prev_first_lsn < cur_txn->first_lsn") ...

waldump for 00000001000000000000000C shows:
grep c1fbc80:
rmgr: Heap2       len (rec/tot):     60/    60, tx:       3398, lsn: 0/0C1FBC80, prev 0/0C1FBC50, desc: NEW_CID rel: 
1663/18763/19987, tid: 0/1, cmin: 1, cmax: 4294967295, combo: 4294967295
rmgr: Heap        len (rec/tot):     59/    59, tx:       3398, lsn: 0/0C1FBCC0, prev 0/0C1FBC80, desc: INSERT+INIT off: 
1, flags: 0x08, blkref #0: rel 1663/18763/19987 blk 0

grep '( 3397| 3398)'
rmgr: Transaction len (rec/tot):     43/    43, tx:       3398, lsn: 0/0C1F2B20, prev 0/0C1F2688, desc: ASSIGNMENT xtop 
3397: subxacts: 3398
rmgr: Heap        len (rec/tot):     59/    59, tx:       3398, lsn: 0/0C1F2B50, prev 0/0C1F2B20, desc: INSERT+INIT off: 
1, flags: 0x08, blkref #0: rel 1663/18763/19981 blk 0
rmgr: Standby     len (rec/tot):     62/    62, tx:          0, lsn: 0/0C1F2BD0, prev 0/0C1F2B90, desc: RUNNING_XACTS 
nextXid 3400 latestCompletedXid 3396 oldestRunningXid 3397; 2 xacts: 3399 3397; 1 subxacts: 3398
rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn: 0/0C1F2C80, prev 0/0C1F2C50, desc: RUNNING_XACTS 
nextXid 3400 latestCompletedXid 3399 oldestRunningXid 3397; 1 xacts: 3397; 1 subxacts: 3398
rmgr: XLOG        len (rec/tot):    114/   114, tx:          0, lsn: 0/0C1F2CC0, prev 0/0C1F2C80, desc: 
CHECKPOINT_ONLINE redo 0/C1F2C10; tli 1; prev tli 1; fpw true; xid 0:3400; oid 24576; multi 13; offset 29; oldest xid 
722 in DB 1; oldest multi 1 in DB 1; oldest/newest commit timestamp xid: 0/0; oldest running xid 3397; online
rmgr: Standby     len (rec/tot):     62/    62, tx:          0, lsn: 0/0C1FBAD0, prev 0/0C1FBAA0, desc: RUNNING_XACTS 
nextXid 3401 latestCompletedXid 3399 oldestRunningXid 3397; 2 xacts: 3400 3397; 1 subxacts: 3398
rmgr: Heap2       len (rec/tot):     60/    60, tx:       3398, lsn: 0/0C1FBC80, prev 0/0C1FBC50, desc: NEW_CID rel: 
1663/18763/19987, tid: 0/1, cmin: 1, cmax: 4294967295, combo: 4294967295
rmgr: Heap        len (rec/tot):     59/    59, tx:       3398, lsn: 0/0C1FBCC0, prev 0/0C1FBC80, desc: INSERT+INIT off: 
1, flags: 0x08, blkref #0: rel 1663/18763/19987 blk 0
rmgr: Transaction len (rec/tot):     54/    54, tx:       3397, lsn: 0/0C1FBD00, prev 0/0C1FBCC0, desc: COMMIT 
2023-06-06 13:55:26.955268 MSK; subxacts: 3398

Best regards,
Alexander





view thread (46+ messages)  latest in thread

Message-ID: <1f860e40-9f95-f0f8-ff4b-4b780f9151ad@gmail.com>
Permalink:  ../1f860e40-9f95-f0f8-ff4b-4b780f9151ad@gmail.com/
Also on:    postgresql.org/message-id/1f860e40-9f95-f0f8-ff4b-4b780f9151ad@gmail.com

 · 

reply
Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: pgsql-hackers@postgresql.org
  Cc: exclusion@gmail.com, tomas.vondra@enterprisedb.com, amit.kapila16@gmail.com, sawada.mshk@gmail.com
  Subject: Re: TRAP: FailedAssertion("prev_first_lsn < cur_txn->first_lsn", File: "reorderbuffer.c", Line: 927, PID: 568639)
  In-Reply-To: <1f860e40-9f95-f0f8-ff4b-4b780f9151ad@gmail.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox