BUG #17791: Assert on procarray.c

The following bug has been logged on the website:

Bug reference: 17791
Logged by: Robins Tharakan
Email address: tharakan(at)gmail(dot)com
PostgreSQL version: 12.14
Operating system: Ubuntu 20.04
Description:

This assert() is:
- Not easily reproducible + rare (~twice a month)
- Always surfaces only on REL_12_STABLE (never on v13+)
- The line numbers changed (in Nov 22) but IIUC its the same signature
- SQLs seem irrelevant. Can dig up full SQLs, if required.
- I provide 4 backtraces, 2 SELECTs, 1 UPDATE, 1 DELETE.

Posting here because I noticed the above pattern today, and thought
someone could identify what's so specifically wrong with v12. Note that
the bug could pre-date Oct 22, since I wasn't aggressively testing older
versions before then.

2022-10-10 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-11-19 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-11-22 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-11-30 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2022-12-09 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2022-12-11 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2023-02-13 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2023-02-13 :TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)

=== Backtrace - PID 3911829 - a5f3f2fce1(at)REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1(at)REL_12_STABLE@sqith: u87
postgres 127.0.0.1(35270) SELECT'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f64ef7cd859 in __GI_abort () at abort.c:79
#2 0x0000562a05a92bb9 in ExceptionalCondition (
conditionName=0x562a05cb9a78 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x562a05cb9a68 "FailedAssertion",
fileName=0x562a05cb9a39 "procarray.c", lineNumber=430) at assert.c:54
#3 0x0000562a058c511d in ProcArrayEndTransaction (proc=0x7f64e7084e90,
latestXid=128185) at procarray.c:430
#4 0x0000562a0551f641 in AbortTransaction () at xact.c:2709
#5 0x0000562a0551ffa0 in AbortCurrentTransaction () at xact.c:3242
#6 0x0000562a058fb4bb in PostgresMain (argc=1, argv=0x562a06ec38b8,
dbname=0x562a06e8b0a8 "postgres", username=0x562a06ec3898 "u87")
at postgres.c:4067
#7 0x0000562a05840a7c in BackendRun (port=0x562a06ec12f0)
at postmaster.c:4517
#8 0x0000562a0584013c in BackendStartup (port=0x562a06ec12f0)
at postmaster.c:4200
#9 0x0000562a0583c016 in ServerLoop () at postmaster.c:1725
#10 0x0000562a0583b7a3 in PostmasterMain (argc=3, argv=0x562a06e89010)
at postmaster.c:1398
#11 0x0000562a0574ee81 in main (argc=3, argv=0x562a06e89010) at main.c:228

=== Backtrace FULL - PID 3911829 - a5f3f2fce1(at)REL_12_STABLE ===
#2 0x0000562a05a92bb9 in ExceptionalCondition (
conditionName=0x562a05cb9a78 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x562a05cb9a68 "FailedAssertion",
fileName=0x562a05cb9a39 "procarray.c", lineNumber=430) at assert.c:54
No locals.
#3 0x0000562a058c511d in ProcArrayEndTransaction (proc=0x7f64e7084e90,
latestXid=128185) at procarray.c:430
pgxact = 0x7f64e70af79c
#4 0x0000562a0551f641 in AbortTransaction () at xact.c:2709
s = 0x562a05e11cc0 <TopTransactionStateData>
latestXid = 128185
is_parallel_worker = false
__func__ = "AbortTransaction"
#5 0x0000562a0551ffa0 in AbortCurrentTransaction () at xact.c:3242
s = 0x562a05e11cc0 <TopTransactionStateData>
#6 0x0000562a058fb4bb in PostgresMain (argc=1, argv=0x562a06ec38b8,
dbname=0x562a06e8b0a8 "postgres", username=0x562a06ec3898 "u87")
at postgres.c:4067
firstchar = 81
input_message = {
data = 0x562a06e8f4b8 "select \n cast(nullif(sample_0.a,\n
(select line_number from pg_catalog.pg_hba_file_rules limit 1 offset 3)\n
) as int4) as c0, \n pg_catalog.pg_is_in_recovery() as c1\nfrom \n
public.fprt2 as s"..., len = 312, maxlen = 1024, cursor = 312}
local_sigjmp_buf = {{__jmpbuf = {94738484097264,
-2389127319967802128, 94738476870288, 140722819967216, 0, 0,

-2389127319737115408, -8253623502494016272},
__mask_was_saved = 1, __saved_mask = {__val = {0, 0, 0, 0,
51539607567, 140722819966272, 94738483588553, 0,
94738485738760, 94738485732538, 51539612060, 4869,
94738504519872, 94738504768168, 4398046511104, 0}}}}
send_ready_for_query = false
disable_idle_in_transaction_timeout = false
__func__ = "PostgresMain"

####################################

=== Backtrace - PID 4149811 - a5f3f2fce1(at)REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1(at)REL_12_STABLE@sqith: u63
postgres 127.0.0.1(53584) DELETE'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f64ef7cd859 in __GI_abort () at abort.c:79
#2 0x0000562a05a92bb9 in ExceptionalCondition (
conditionName=0x562a05cb9a78 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x562a05cb9a68 "FailedAssertion",
fileName=0x562a05cb9a39 "procarray.c", lineNumber=430) at assert.c:54
#3 0x0000562a058c511d in ProcArrayEndTransaction (proc=0x7f64e6d5ba00,
latestXid=340911) at procarray.c:430
#4 0x0000562a0551f641 in AbortTransaction () at xact.c:2709
#5 0x0000562a0551ffa0 in AbortCurrentTransaction () at xact.c:3242
#6 0x0000562a058fb4bb in PostgresMain (argc=1, argv=0x562a06ede610,
dbname=0x562a06ede5e8 "postgres", username=0x562a06e8b0b8 "u63")
at postgres.c:4067
#7 0x0000562a05840a7c in BackendRun (port=0x562a06ef8260)
at postmaster.c:4517
#8 0x0000562a0584013c in BackendStartup (port=0x562a06ef8260)
at postmaster.c:4200
#9 0x0000562a0583c016 in ServerLoop () at postmaster.c:1725
#10 0x0000562a0583b7a3 in PostmasterMain (argc=3, argv=0x562a06e89010)
at postmaster.c:1398
#11 0x0000562a0574ee81 in main (argc=3, argv=0x562a06e89010) at main.c:228

=== Backtrace FULL - PID 4149811 - a5f3f2fce1(at)REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1(at)REL_12_STABLE@sqith: u63
postgres 127.0.0.1(53584) DELETE'.
Program terminated with signal SIGABRT, Aborted.
#2 0x0000562a05a92bb9 in ExceptionalCondition (
conditionName=0x562a05cb9a78 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x562a05cb9a68 "FailedAssertion",
fileName=0x562a05cb9a39 "procarray.c", lineNumber=430) at assert.c:54
No locals.
#3 0x0000562a058c511d in ProcArrayEndTransaction (proc=0x7f64e6d5ba00,
latestXid=340911) at procarray.c:430
pgxact = 0x7f64e70a4060
#4 0x0000562a0551f641 in AbortTransaction () at xact.c:2709
s = 0x562a05e11cc0 <TopTransactionStateData>
latestXid = 340911
is_parallel_worker = false
__func__ = "AbortTransaction"
#5 0x0000562a0551ffa0 in AbortCurrentTransaction () at xact.c:3242
s = 0x562a05e11cc0 <TopTransactionStateData>
#6 0x0000562a058fb4bb in PostgresMain (argc=1, argv=0x562a06ede610,
dbname=0x562a06ede5e8 "postgres", username=0x562a06e8b0b8 "u63")
at postgres.c:4067
firstchar = 81
input_message = {
data = 0x562a06e8f4b8 "delete from sqithsch24.dt\nwhere
\n(pg_catalog.getdatabaseencoding() is not NULL) \n or
(cast(coalesce((select c2 from import_dest2.t3 limit 1 offset 4)\n
,\n cast(coalesce((select c2 from imp"..., len = 695, maxlen = 1024,
cursor = 695}
local_sigjmp_buf = {{__jmpbuf = {94738484097264,
-2389127319967802128, 94738476870288, 140722819967216, 0, 0,

-2389127319737115408, -8253623502494016272},
__mask_was_saved = 1, __saved_mask = {__val = {0, 0, 0, 0,
51539607567, 140722819966272, 94738483588553, 0,
94738485738760, 94738485732538, 51539612060, 4869,
94738504519872, 94738504911848, 4398046511104, 0}}}}
send_ready_for_query = false
disable_idle_in_transaction_timeout = false
__func__ = "PostgresMain"

##########################################################

=== Backtrace - PID 1447940 - e21856fd65(at)REL_12_STABLE ===
Core was generated by `postgres: e21856fd65(at)REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(46898) SELE'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007ffb7c54c859 in __GI_abort () at abort.c:79
#2 0x000055cebc3064e4 in ExceptionalCondition (
conditionName=0x55cebc52bed8 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x55cebc52bec8 "FailedAssertion",
fileName=0x55cebc52be99 "procarray.c", lineNumber=419) at assert.c:54
#3 0x000055cebc13dbf1 in ProcArrayEndTransaction (proc=0x7ffb76841e80,
latestXid=33358) at procarray.c:419
#4 0x000055cebbd9c956 in AbortTransaction () at xact.c:2709
#5 0x000055cebbd9d2b5 in AbortCurrentTransaction () at xact.c:3242
#6 0x000055cebc173d49 in PostgresMain (argc=1, argv=0x55cebd21e6c8,
dbname=0x55cebd1aeb88 "postgres", username=0x55cebd21e6a8 "ubuntu")
at postgres.c:4055
#7 0x000055cebc0b969f in BackendRun (port=0x55cebd2156b0)
at postmaster.c:4510
#8 0x000055cebc0b8d73 in BackendStartup (port=0x55cebd2156b0)
at postmaster.c:4193
#9 0x000055cebc0b4db1 in ServerLoop () at postmaster.c:1725
#10 0x000055cebc0b453e in PostmasterMain (argc=3, argv=0x55cebd1acad0)
at postmaster.c:1398
#11 0x000055cebbfc8077 in main (argc=3, argv=0x55cebd1acad0) at main.c:228

=== Backtrace FULL - PID 1447940 - e21856fd65(at)REL_12_STABLE ===
Core was generated by `postgres: e21856fd65(at)REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(46898) SELE'.
Program terminated with signal SIGABRT, Aborted.
#2 0x000055cebc3064e4 in ExceptionalCondition (
conditionName=0x55cebc52bed8 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x55cebc52bec8 "FailedAssertion",
fileName=0x55cebc52be99 "procarray.c", lineNumber=419) at assert.c:54
No locals.
#3 0x000055cebc13dbf1 in ProcArrayEndTransaction (proc=0x7ffb76841e80,
latestXid=33358) at procarray.c:419
pgxact = 0x7ffb76a14640
#4 0x000055cebbd9c956 in AbortTransaction () at xact.c:2709
s = 0x55cebc681c80 <TopTransactionStateData>
latestXid = 33358
is_parallel_worker = false
__func__ = "AbortTransaction"
#5 0x000055cebbd9d2b5 in AbortCurrentTransaction () at xact.c:3242
s = 0x55cebc681c80 <TopTransactionStateData>
#6 0x000055cebc173d49 in PostgresMain (argc=1, argv=0x55cebd21e6c8,
dbname=0x55cebd1aeb88 "postgres", username=0x55cebd21e6a8 "ubuntu")
at postgres.c:4055
firstchar = 81
input_message = {
data = 0x55cebd1b3848 "select \n
pg_catalog.getdatabaseencoding() as c0, \n case when
pg_catalog.statement_timestamp() is not NULL then
pg_catalog.pg_get_function_arguments(\n cast(cast(null as oid) as oid))
else pg_ca"..., len = 1063, maxlen = 2048, cursor = 1063}
local_sigjmp_buf = {{__jmpbuf = {94346409419472,
5411436918575294414,
94346402234016, 140728059150544, 0, 0, 5411436918529157070,
2269720658606647246}, __mask_was_saved = 1, __saved_mask = {
__val = {0, 0, 0, 0, 51539607567, 140728059149600,
94346408912601, 0, 94346411057624, 94346411051418,
51539612053, 4869, 94346424273824, 94346424748216,
4398046511104, 0}}}}
send_ready_for_query = false
disable_idle_in_transaction_timeout = false
__func__ = "PostgresMain"

#############################################

=== Backtrace - PID 271497 - 7b96f525cd(at)REL_12_STABLE ===
Core was generated by `postgres: 7b96f525cd(at)REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(39634) UPDA'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig(at)entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007fb220668859 in __GI_abort () at abort.c:79
#2 0x00005651346645e1 in ExceptionalCondition (
conditionName=0x565134889f18 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x565134889f08 "FailedAssertion",
fileName=0x565134889ed9 "procarray.c", lineNumber=430) at assert.c:54
#3 0x000056513449bbad in ProcArrayEndTransaction (proc=0x7fb21a919cb0,
latestXid=30504) at procarray.c:430
#4 0x00005651340fa96c in AbortTransaction () at xact.c:2709
#5 0x00005651340fb2cb in AbortCurrentTransaction () at xact.c:3242
#6 0x00005651344d1ddb in PostgresMain (argc=1, argv=0x565135fee5d8,
dbname=0x565135f7eb88 "postgres", username=0x565135fee5b8 "ubuntu")
at postgres.c:4055
#7 0x0000565134417611 in BackendRun (port=0x565135fd9590)
at postmaster.c:4510
#8 0x0000565134416ce5 in BackendStartup (port=0x565135fd9590)
at postmaster.c:4193
#9 0x0000565134412d23 in ServerLoop () at postmaster.c:1725
#10 0x00005651344124b0 in PostmasterMain (argc=3, argv=0x565135f7cad0)
at postmaster.c:1398
#11 0x0000565134326097 in main (argc=3, argv=0x565135f7cad0) at main.c:228

=== Backtrace FULL - PID 271497 - 7b96f525cd(at)REL_12_STABLE ===
Core was generated by `postgres: 7b96f525cd(at)REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(39634) UPDA'.
#2 0x00005651346645e1 in ExceptionalCondition (
conditionName=0x565134889f18 "!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", errorType=0x565134889f08 "FailedAssertion",
fileName=0x565134889ed9 "procarray.c", lineNumber=430) at assert.c:54
No locals.
#3 0x000056513449bbad in ProcArrayEndTransaction (proc=0x7fb21a919cb0,
latestXid=30504) at procarray.c:430
pgxact = 0x7fb21ab2f6d4
#4 0x00005651340fa96c in AbortTransaction () at xact.c:2709
s = 0x5651349dfc80 <TopTransactionStateData>
latestXid = 30504
is_parallel_worker = false
__func__ = "AbortTransaction"
#5 0x00005651340fb2cb in AbortCurrentTransaction () at xact.c:3242
s = 0x5651349dfc80 <TopTransactionStateData>
#6 0x00005651344d1ddb in PostgresMain (argc=1, argv=0x565135fee5d8,
dbname=0x565135f7eb88 "postgres", username=0x565135fee5b8 "ubuntu")
at postgres.c:4055
firstchar = 81
input_message = {
data = 0x565135f83848 "update sch18.dt set \n d =
cast(nullif(sch18.dt.d,\n sch18.dt.d) as date)\nreturning \n
pg_catalog.pg_client_encoding() as c0, \n
cast(coalesce(pg_catalog.pg_conf_load_time(),\n case when pg_catalo"...,
len = 2357, maxlen = 4096, cursor = 2357}
local_sigjmp_buf = {{__jmpbuf = {94906771964864,
3111189373843782306,
94906764779168, 140737476492032, 0, 0, 3111189373915085474,
8678643532193970850}, __mask_was_saved = 1, __saved_mask = {
__val = {0, 0, 0, 0, 51539607567, 140737476491088,
94906771458006, 0, 94906773602744, 94906773596538,
51539612053, 4869, 94906797771680, 94906798245832,
4398046511104, 0}}}}
send_ready_for_query = false
disable_idle_in_transaction_timeout = false
__func__ = "PostgresMain"

Thanks to SQLSmith for the find.

-
Robins Tharakan
Amazon Web Services