Re: TRAP: FailedAssertion("tabstat->trans == trans", File: "pgstat_relation.c", Line: 508

Op 19-04-2022 om 19:36 schreef Andres Freund:
> Hi,
>
> On 2022-04-19 13:50:25 +0200, Erik Rijkers wrote:
>> The 12th run of statbug.sh crashed and gave a corefile.
>
> I ran through quite a few iterations by now, without reproducing :(
>
> I guess there's some timing issue and you're hitting on your system
> due to the slower disks.
>
>
>> Program terminated with signal 6, Aborted.
>> #0 0x000000357d6324f5 in raise () from /lib64/libc.so.6
>> (gdb) bt
>> #0 0x000000357d6324f5 in raise () from /lib64/libc.so.6
>> #1 0x000000357d633cd5 in abort () from /lib64/libc.so.6
>> #2 0x0000000000b3bada in ExceptionalCondition (conditionName=0xd389a1
>> "tabstat->trans == trans", errorType=0xd388b2 "FailedAssertion",
>> fileName=0xd388a0 "pgstat_relation.c", lineNumber=508) at assert.c:69
>> #3 0x00000000009bf5dc in AtEOXact_PgStat_Relations (xact_state=0x31b1b50,
>> isCommit=true) at pgstat_relation.c:508
>> #4 0x00000000009c4107 in AtEOXact_PgStat (isCommit=true, parallel=false) at
>> pgstat_xact.c:54
>> #5 0x0000000000583764 in CommitTransaction () at xact.c:2360
>> #6 0x0000000000584354 in CommitTransactionCommand () at xact.c:3048
>> #7 0x000000000090b34e in apply_handle_commit_internal
>> (commit_data=0x7ffd024b5940) at worker.c:1532
>> #8 0x000000000090a287 in apply_handle_commit (s=0x7ffd024b59b0) at
>> worker.c:845
>> #9 0x000000000090ce3a in apply_dispatch (s=0x7ffd024b59b0) at worker.c:2473
>> #10 0x000000000090d41c in LogicalRepApplyLoop (last_received=74680880) at
>> worker.c:2757
>> #11 0x000000000090e974 in start_apply (origin_startpos=0) at worker.c:3526
>> #12 0x000000000090f156 in ApplyWorkerMain (main_arg=0) at worker.c:3782
>> #13 0x00000000008c7623 in StartBackgroundWorker () at bgworker.c:858
>> #14 0x00000000008d1557 in do_start_bgworker (rw=0x30ff0a0) at
>> postmaster.c:5802
>> #15 0x00000000008d1903 in maybe_start_bgworkers () at postmaster.c:6026
>> #16 0x00000000008d09ba in sigusr1_handler (postgres_signal_arg=10) at
>> postmaster.c:5191
>> #17 <signal handler called>
>> #18 0x000000357d6e1683 in __select_nocancel () from /lib64/libc.so.6
>> #19 0x00000000008cc6c1 in ServerLoop () at postmaster.c:1757
>> #20 0x00000000008cc0aa in PostmasterMain (argc=11, argv=0x30d6590) at
>> postmaster.c:1465
>> #21 0x00000000007c9256 in main (argc=11, argv=0x30d6590) at main.c:202
>> (gdb) f 3
>> #3 0x00000000009bf5dc in AtEOXact_PgStat_Relations (xact_state=0x31b1b50,
>> isCommit=true) at pgstat_relation.c:508
>> 508 Assert(tabstat->trans == trans);
>> (gdb) p tabstat
>> $1 = (PgStat_TableStatus *) 0x319e630
>> (gdb) p *tabstat
>> $2 = {t_id = 2139062143, t_shared = 127, trans = 0x7f7f7f7f7f7f7f7f,
>> t_counts = {t_numscans = 9187201950435737471, t_tuples_returned =
>> 9187201950435737471, t_tuples_fetched = 9187201950435737471,
>> t_tuples_inserted = 9187201950435737471, t_tuples_updated =
>> 9187201950435737471, t_tuples_deleted = 9187201950435737471,
>> t_tuples_hot_updated = 9187201950435737471, t_truncdropped = 127,
>> t_delta_live_tuples = 9187201950435737471, t_delta_dead_tuples =
>> 9187201950435737471, t_changed_tuples = 9187201950435737471,
>> t_blocks_fetched = 9187201950435737471, t_blocks_hit = 9187201950435737471},
>> relation = 0x7f7f7f7f7f7f7f7f}
>> (gdb) p trans
>> $3 = (PgStat_TableXactStatus *) 0x31b1ba8
>> (gdb) p *trans
>> $4 = {tuples_inserted = 1, tuples_updated = 0, tuples_deleted = 0,
>> truncdropped = false, inserted_pre_truncdrop = 0, updated_pre_truncdrop = 0,
>> deleted_pre_truncdrop = 0, nest_level = 1, upper = 0x0,
>> parent = 0x319e630, next = 0x31b1ab8}
>> (gdb)
>
> Could you print out
> p xact_state
> p *xact_state
> p xact_state->first
> p *xact_state->first
>
> Do you have the server log file for the failed run / instance?

(gdb) p xact_state
$5 = (PgStat_SubXactStatus *) 0x31b1b50

(gdb) p *xact_state
$6 = {nest_level = 1, prev = 0x0, pending_drops = {head = {prev =
0x31b1b60, next = 0x31b1b60}}, pending_drops_count = 0, first = 0x31b1ba8}

(gdb) p xact_state->first
$7 = (PgStat_TableXactStatus *) 0x31b1ba8

(gdb) p *xact_state->first
$8 = {tuples_inserted = 1, tuples_updated = 0, tuples_deleted = 0,
truncdropped = false, inserted_pre_truncdrop = 0, updated_pre_truncdrop
= 0, deleted_pre_truncdrop = 0, nest_level = 1, upper = 0x0,
parent = 0x319e630, next = 0x31b1ab8}
(gdb)

The logfile is attached.

Erik

> Greetings,
>
> Andres Freund