Обсуждение: 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@gmail.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@REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1@REL_12_STABLE@sqith: u87
postgres 127.0.0.1(35270) SELECT'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig@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@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@REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1@REL_12_STABLE@sqith: u63
postgres 127.0.0.1(53584) DELETE'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig@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@REL_12_STABLE ===
Core was generated by `postgres: a5f3f2fce1@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@REL_12_STABLE ===
Core was generated by `postgres: e21856fd65@REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(46898) SELE'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig@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@REL_12_STABLE ===
Core was generated by `postgres: e21856fd65@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@REL_12_STABLE ===
Core was generated by `postgres: 7b96f525cd@REL_12_STABLE@sqith: ubuntu
postgres 127.0.0.1(39634) UPDA'.
Program terminated with signal SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#0 __GI_raise (sig=sig@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@REL_12_STABLE ===
Core was generated by `postgres: 7b96f525cd@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
Hi, On 2023-02-14 03:25:04 +0000, PG Bug reporting form wrote: > The following bug has been logged on the website: > > Bug reference: 17791 > Logged by: Robins Tharakan > Email address: tharakan@gmail.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. Are there any log messages around the crashes? I'm wondering whether we're erroring out while aborting, to then abort again, or such. Which will often elicit warning/error messages. Unfortunately, without further information, I doubt this is sufficient for anybody to debug the issue. The stack traces all seem to be during error handling, after catching an error in PostgresMain(). So there's really not much to go on. Greetings, Andres Freund
Hi Andreas,
> Are there any log messages around the crashes? I'm wondering whether we're
> erroring out while aborting, to then abort again, or such. Which will often
> elicit warning/error messages.
Thanks for taking a look and possibly you're correct with your
assumption. I mean I see a ton of FATALs but let me know if I am
mistaken in assuming them to be harmless (since they just convey that
the client's gone away)?
Nonetheless, I have provided error logs going back till Oct 22 just in
case the engine can recover from some of those scenarios. Two things
about the test scenario that may be relevant:
1. Since performance was the least of my worries, the postgres server
and the client workload are on the same box. Add dblink / FDW to this
mix, and it is easy to end up with a ton of loopback connections
(think SELECT dblink_conect() FROM pg_catalog.pg_class) - IMO
noteworthy, since there are a ton of "Broken pipe"s and one instance
of 'too many file descriptors'.
2. All versions are subjected to similar workload and it is possible
that v13+ has generally improved in this area, and thus this possibly
crashes less? Unsure.
Hope it helps.
################################################
2023-02-13 10:10:08.474 UTC [3918683] LOG: could not send data to
client: Broken pipe
2023-02-13 10:10:08.474 UTC [3918683] FATAL: connection to client lost
2023-02-13 10:10:15.001 UTC [3918764] LOG: could not send data to
client: Broken pipe
2023-02-13 10:10:15.001 UTC [3918764] FATAL: connection to client lost
2023-02-13 10:10:25.268 UTC [3918886] LOG: could not send data to
client: Broken pipe
2023-02-13 10:10:25.269 UTC [3918886] FATAL: connection to client lost
2023-02-13 10:10:26.261 UTC [3918897] LOG: could not send data to
client: Broken pipe
2023-02-13 10:10:26.261 UTC [3918897] FATAL: connection to client lost
2023-02-13 10:10:29.503 UTC [3918930] LOG: could not send data to
client: Broken pipe
2023-02-13 10:10:29.503 UTC [3918930] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2023-02-13 10:10:41.629 UTC [3918961] LOG: could not receive data
from client: Connection reset by peer
2023-02-13 10:10:43.008 UTC [3777407] LOG: server process (PID
3911829) was terminated by signal 6: Aborted
2023-02-13 10:10:43.008 UTC [3777407] DETAIL: Failed process was
running: select
cast(nullif(sample_0.a,
(select line_number from pg_catalog.pg_hba_file_rules
limit 1 offset 3)
) as int4) as c0,
pg_catalog.pg_is_in_recovery() as c1
from
public.fprt2 as sample_0 tablesample bernoulli (1.2)
where public.test_found() > pg_catalog.pg_is_wal_replay_paused()
limit 111
2023-02-13 10:10:43.008 UTC [3777407] LOG: terminating any other
active server processes
2023-02-13 10:10:43.340 UTC [3777407] LOG: all server processes
terminated; reinitializing
2023-02-13 10:10:43.472 UTC [3919088] LOG: database system was
interrupted; last known up at 2023-02-13 10:09:22 UTC
2023-02-13 10:10:43.534 UTC [3919088] LOG: database system was not
properly shut down; automatic recovery in progress
2023-02-13 10:10:43.540 UTC [3919088] LOG: redo starts at 2C/473107C8
2023-02-13 10:10:44.043 UTC [3919094] FATAL: the database system is
in recovery mode
################################################
2023-02-13 13:48:00.083 UTC [4073] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:00.083 UTC [4073] FATAL: connection to client lost
2023-02-13 13:48:07.916 UTC [4174] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:07.916 UTC [4174] FATAL: connection to client lost
2023-02-13 13:48:16.689 UTC [4193172] LOG: duration: 247511.694 ms
statement: REINDEX INDEX sqithsch4.chr_c_idx4;
2023-02-13 13:48:17.247 UTC [4192307] LOG: duration: 250514.066 ms
statement: REINDEX INDEX sqithsch7.chr_c_idx4;
2023-02-13 13:48:19.108 UTC [4193744] LOG: duration: 248244.637 ms
statement: REINDEX INDEX sqithsch8.chr_c_idx4;
2023-02-13 13:48:19.660 UTC [4191898] LOG: duration: 253850.202 ms
statement: REINDEX INDEX sqithsch25.chr_c_idx4;
2023-02-13 13:48:20.607 UTC [4193307] LOG: duration: 250962.064 ms
statement: REINDEX INDEX sqithsch1.chr_c_idx4;
2023-02-13 13:48:20.857 UTC [4321] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:20.857 UTC [4321] FATAL: connection to client lost
2023-02-13 13:48:24.460 UTC [4377] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:24.460 UTC [4377] FATAL: connection to client lost
2023-02-13 13:48:25.059 UTC [4194142] LOG: duration: 251910.592 ms
statement: REINDEX INDEX sqithsch17.chr_c_idx4_ccnew;
2023-02-13 13:48:33.644 UTC [460] LOG: duration: 248070.798 ms
statement: REINDEX INDEX sqithsch29.chr_c_idx4;
2023-02-13 13:48:33.739 UTC [632] LOG: duration: 240490.057 ms
statement: REINDEX INDEX sqithsch14.chr_c_idx4;
2023-02-13 13:48:50.101 UTC [4664] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:50.101 UTC [4664] FATAL: connection to client lost
2023-02-13 13:48:55.741 UTC [4725] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:55.741 UTC [4725] FATAL: connection to client lost
2023-02-13 13:48:55.991 UTC [2434] LOG: duration: 192161.947 ms
statement: REINDEX INDEX sqithsch12.chr_c_idx4;
2023-02-13 13:48:56.021 UTC [4737] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:56.021 UTC [4737] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2023-02-13 13:48:56.479 UTC [2349] LOG: duration: 193350.243 ms
statement: REINDEX INDEX sqithsch27.chr_c_idx4;
2023-02-13 13:48:56.679 UTC [2438] LOG: duration: 192801.918 ms
statement: REINDEX INDEX sqithsch13.chr_c_idx4_ccnew_ccnew;
2023-02-13 13:48:58.428 UTC [4748] LOG: could not receive data from
client: Connection reset by peer
2023-02-13 13:48:58.677 UTC [4773] LOG: could not send data to
client: Broken pipe
2023-02-13 13:48:58.677 UTC [4773] FATAL: connection to client lost
2023-02-13 13:49:01.002 UTC [1487] LOG: duration: 232718.744 ms
statement: REINDEX INDEX sqithsch28.chr_c_idx4;
2023-02-13 13:49:02.393 UTC [4806] FATAL: terminating connection due
to administrator command
2023-02-13 13:49:02.393 UTC [4806] STATEMENT: ALTER TABLE ONLY sqithsch18.chr
ALTER COLUMN c SET DATA TYPE TEXT USING sqithsch18.chr.c
2023-02-13 13:49:02.470 UTC [3777407] LOG: background worker
"parallel worker" (PID 4806) exited with exit code 1
2023-02-13 13:49:02.787 UTC [832] LOG: duration: 255613.229 ms
statement: REINDEX INDEX sqithsch13.chr_c_idx4;
2023-02-13 13:49:02.961 UTC [3777407] LOG: server process (PID
4149811) was terminated by signal 6: Aborted
2023-02-13 13:49:02.961 UTC [3777407] DETAIL: Failed process was
running: delete from sqithsch24.dt
where
(pg_catalog.getdatabaseencoding() is not NULL)
or (cast(coalesce((select c2 from import_dest2.t3 limit 1 offset 4)
,
cast(coalesce((select c2 from import_dest1.t3 limit 1 offset 4)
,
cast(nullif((select c2 from import_dest2.t3 limit 1 offset 37)
,
cast(null as public.typ1)) as public.typ1)) as
public.typ1)) as public.typ1) *>= cast(nullif(cast(null as
public.typ1),
cast(null as public.typ1)) as public.typ1))
returning
sqithsch24.dt.d as c0,
public.namedparmcursor_test8() as c1,
pg_catalog.pg_current_wal_flush_lsn() as c2,
pg_catalog.now() as c3,
pg_catalog.session_user() as c4
2023-02-13 13:49:02.961 UTC [3777407] LOG: terminating any other
active server processes
2023-02-13 13:49:03.264 UTC [3777407] LOG: all server processes
terminated; reinitializing
2023-02-13 13:49:03.399 UTC [4848] LOG: database system was
interrupted; last known up at 2023-02-13 13:47:57 UTC
2023-02-13 13:49:04.043 UTC [4849] FATAL: the database system is in
recovery mode
2023-02-13 13:49:04.046 UTC [4850] FATAL: the database system is in
recovery mode
################################################
2022-12-09 15:41:07.667 UTC [515871] LOG: could not send data to
client: Broken pipe
2022-12-09 15:41:07.686 UTC [515871] FATAL: connection to client lost
2022-12-09 15:41:14.794 UTC [516872] LOG: could not send data to
client: Broken pipe
2022-12-09 15:41:14.794 UTC [516872] FATAL: connection to client lost
2022-12-09 15:41:54.815 UTC [517815] LOG: could not send data to
client: Broken pipe
2022-12-09 15:41:54.815 UTC [517815] FATAL: connection to client lost
2022-12-09 15:42:09.856 UTC [519130] LOG: could not send data to
client: Broken pipe
2022-12-09 15:42:09.856 UTC [519130] FATAL: connection to client lost
2022-12-09 15:42:11.424 UTC [519753] LOG: could not send data to
client: Broken pipe
2022-12-09 15:42:11.424 UTC [519753] FATAL: connection to client lost
2022-12-09 15:42:37.653 UTC [521507] LOG: could not send data to
client: Broken pipe
2022-12-09 15:42:37.653 UTC [521507] FATAL: connection to client lost
2022-12-09 15:43:34.469 UTC [522743] LOG: could not send data to
client: Broken pipe
2022-12-09 15:43:34.469 UTC [522743] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2022-12-09 15:43:44.272 UTC [522120] LOG: could not receive data from
client: Connection reset by peer
2022-12-09 15:43:47.381 UTC [336681] LOG: server process (PID 522114)
was terminated by signal 6: Aborted
2022-12-09 15:43:47.381 UTC [336681] DETAIL: Failed process was running: select
public.test_found() as c0,
public.dblink_current_query() as c1,
case when pg_catalog.pg_last_wal_receive_lsn() <
pg_catalog.pg_current_wal_lsn() then ref_0.random else ref_0.random
end
as c2,
pg_catalog.phraseto_tsquery(
cast(pg_catalog.get_current_ts_config() as regconfig),
cast(cast(coalesce(public.dblink_connect_u(
cast(pg_catalog.timeofday() as text),
cast(public.connection_parameters() as text)),
pg_catalog.to_char(
cast(cast(null as "interval") as "interval"),
cast(pg_catalog.current_query() as text))) as text) as
text)) as c3
from
public.random_tbl as ref_0
right join sch3.chr_fdw as ref_1
on (cast(null as tsquery) <@ (select tsquery from
public.tab_core_types limit 1 offset 5)
)
where (pg_catalog.int8send(
cast(cast(null as int8) as int8)) ~~ cast(coalesce(public.hmac(
cast(pg_catalog.cstring_send(
cast(pg_catalog.regroleout(
cast(cast(null as regrole) as regrole)) as cstrin
2022-12-09 15:43:47.381 UTC [336681] LOG: terminating any other
active server processes
2022-12-09 15:43:47.387 UTC [522266] LOG: could not send data to
client: Broken pipe
################################################
2022-12-11 12:35:53.840 UTC [1739971] LOG: out of file descriptors:
Too many open files; release and retry
2022-12-11 12:35:53.840 UTC [1739971] STATEMENT: select
public.lquery_in(
cast(public.citextout(
cast(public.citext(
cast(pg_catalog.bpchar(
cast(cast(null as bpchar) as bpchar),
cast(subq_0.c1 as int4),
cast(case when (62 is NULL)
and ((true)
or (true)) then (select pg_catalog.bool_or(b)
from sch23.bool)
else (select pg_catalog.bool_or(b) from sch23.bool)
end
as bool)) as bpchar)) as public.citext)) as
cstring)) as c0,
public.reraise_test() as c1,
sample_4.c1 as c2,
pg_catalog.tstzrange(
cast(pg_catalog.clock_timestamp() as timestamptz),
cast(pg_catalog.pg_stat_get_bgwriter_stat_reset_time() as
timestamptz),
cast((select t from sch32.txt limit 1 offset 3)
as text)) as c3
from
sch8.txt as ref_0
inner join (select
sample_0.a as c0,
sample_0.a as c1,
sample_0.a as c2,
sample_0.a as c3,
sample_0.a as c4,
sample_0.a as c5,
sample_0.a as c6
from
fkpart5.fk4 as sample_0 tablesample system (3.8)
where sample_0.a is NULL
limit 177) as subq_0
on (cast(null as public.ltree) = (select t from
public.ltreetest limit 1 offset 4)
)
left join (select
ref_1.t as c0,
subq_1.c5 as c1,
66 as c2
from
sch8.vec_fdw as ref_1,
lateral (select
sample_1.even as c0,
sample_1.two as c1,
sample_1.fivethous as c2,
sample_1.fivethous as c3,
sample_1.two as c4,
ref_1.o as c5,
ref_1.i as c6
from
public.tenk2 as sample_1 tablesample system (5.7)
where (select public.logging_agg_strict(t)
from sch23.txt)
~* cast(null as text)
limit 139) as subq_1
where cast(null as uuid) < cast(null as uuid)
limit 139) as subq_2
on (subq_0.c5 is NULL)
inner join public.plt1 as sample_2 tablesample system (0.6)
right join public.fprt1 as sample_3 tablesample system (6.5)
right join (select
ref_2.f as c0,
ref_2.f as c1,
ref_2.f as c2
from
sch29.flot as ref_2
where cast(null as jsonb) <= cast(null as jsonb)
limit 62) as subq_3
right join import_source.t5 as sample_4 tablesample
system (3.3)
inner join import_dest2.t1 as ref_3
right join public.table_with_pkey as sample_5
tablesample system (1.3)
on (cast(null as bpchar) ~~* (select t from
sch27.txt limit 1 offset 4)
)
on (true)
on ((select timestamptz from public.tab_core_types
limit 1 offset 1)
<> (select timestamptzcol from
public.brintest limit 1 offset 3)
)
on (sample_4.c2 > sample_4.c2)
on (sample_2.b = ref_3.c1 )
on (subq_2.c2 = sample_4.c1 )
where false
limit 84
2022-12-11 12:35:53.845 UTC [1806036] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:53.845 UTC [1806036] FATAL: connection to client lost
2022-12-11 12:35:54.357 UTC [1806042] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:54.357 UTC [1806042] FATAL: connection to client lost
2022-12-11 12:35:54.969 UTC [1806049] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:54.969 UTC [1806049] FATAL: connection to client lost
2022-12-11 12:35:55.018 UTC [1806050] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:55.018 UTC [1806050] FATAL: connection to client lost
2022-12-11 12:35:55.123 UTC [1806051] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:55.123 UTC [1806051] FATAL: connection to client lost
2022-12-11 12:35:55.610 UTC [1806052] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:55.610 UTC [1806052] FATAL: connection to client lost
2022-12-11 12:35:55.730 UTC [1806053] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:55.730 UTC [1806053] FATAL: connection to client lost
2022-12-11 12:35:55.817 UTC [1806058] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:55.817 UTC [1806058] FATAL: connection to client lost
2022-12-11 12:35:57.141 UTC [1806060] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:57.141 UTC [1806060] FATAL: connection to client lost
2022-12-11 12:35:57.753 UTC [1806066] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:57.753 UTC [1806066] FATAL: connection to client lost
2022-12-11 12:35:58.164 UTC [1806072] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:58.164 UTC [1806072] FATAL: connection to client lost
2022-12-11 12:35:58.824 UTC [1806080] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:58.824 UTC [1806080] FATAL: connection to client lost
2022-12-11 12:35:58.965 UTC [1806081] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:58.965 UTC [1806081] FATAL: connection to client lost
2022-12-11 12:35:59.260 UTC [1806082] LOG: could not send data to
client: Broken pipe
2022-12-11 12:35:59.260 UTC [1806082] FATAL: connection to client lost
2022-12-11 12:36:00.604 UTC [1806099] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:00.604 UTC [1806099] FATAL: connection to client lost
2022-12-11 12:36:01.960 UTC [1806118] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:01.960 UTC [1806118] FATAL: connection to client lost
2022-12-11 12:36:03.109 UTC [1806125] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:03.109 UTC [1806125] FATAL: connection to client lost
2022-12-11 12:36:03.194 UTC [1806126] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:03.194 UTC [1806126] FATAL: connection to client lost
2022-12-11 12:36:04.707 UTC [1806235] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:04.707 UTC [1806235] FATAL: connection to client lost
2022-12-11 12:36:05.296 UTC [1806241] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.296 UTC [1806241] FATAL: connection to client lost
2022-12-11 12:36:05.484 UTC [1806242] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.484 UTC [1806242] FATAL: connection to client lost
2022-12-11 12:36:05.620 UTC [1806243] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.620 UTC [1806243] FATAL: connection to client lost
2022-12-11 12:36:05.663 UTC [1806244] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.663 UTC [1806244] FATAL: connection to client lost
2022-12-11 12:36:05.784 UTC [1806245] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.784 UTC [1806245] FATAL: connection to client lost
2022-12-11 12:36:05.863 UTC [1806246] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.863 UTC [1806246] FATAL: connection to client lost
2022-12-11 12:36:05.981 UTC [1806252] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:05.981 UTC [1806252] FATAL: connection to client lost
2022-12-11 12:36:06.020 UTC [1806253] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:06.020 UTC [1806253] FATAL: connection to client lost
2022-12-11 12:36:06.161 UTC [1806254] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:06.161 UTC [1806254] FATAL: connection to client lost
2022-12-11 12:36:06.313 UTC [1806255] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:06.313 UTC [1806255] FATAL: connection to client lost
2022-12-11 12:36:07.639 UTC [1806262] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:07.639 UTC [1806262] FATAL: connection to client lost
2022-12-11 12:36:07.880 UTC [1806263] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:07.880 UTC [1806263] FATAL: connection to client lost
2022-12-11 12:36:08.529 UTC [1806269] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:08.529 UTC [1806269] FATAL: connection to client lost
2022-12-11 12:36:10.989 UTC [1806366] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:10.989 UTC [1806366] FATAL: connection to client lost
2022-12-11 12:36:11.936 UTC [1806457] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:11.936 UTC [1806457] FATAL: connection to client lost
2022-12-11 12:36:12.298 UTC [1806458] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:12.298 UTC [1806458] FATAL: connection to client lost
2022-12-11 12:36:12.688 UTC [1806467] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:12.688 UTC [1806467] FATAL: connection to client lost
2022-12-11 12:36:13.005 UTC [1806473] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:13.005 UTC [1806473] FATAL: connection to client lost
2022-12-11 12:36:14.021 UTC [1806480] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:14.021 UTC [1806480] FATAL: connection to client lost
2022-12-11 12:36:14.357 UTC [1806481] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:14.357 UTC [1806481] FATAL: connection to client lost
2022-12-11 12:36:14.602 UTC [1806482] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:14.602 UTC [1806482] FATAL: connection to client lost
2022-12-11 12:36:15.333 UTC [1806489] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:15.333 UTC [1806489] FATAL: connection to client lost
2022-12-11 12:36:15.989 UTC [1806493] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:15.989 UTC [1806493] FATAL: connection to client lost
2022-12-11 12:36:16.245 UTC [1806515] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:16.245 UTC [1806515] FATAL: connection to client lost
2022-12-11 12:36:16.317 UTC [1806532] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:16.317 UTC [1806532] FATAL: connection to client lost
2022-12-11 12:36:16.862 UTC [1806609] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:16.873 UTC [1806609] FATAL: connection to client lost
2022-12-11 12:36:17.170 UTC [1806680] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:17.170 UTC [1806680] FATAL: connection to client lost
2022-12-11 12:36:17.405 UTC [1806738] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:17.405 UTC [1806738] FATAL: connection to client lost
2022-12-11 12:36:18.061 UTC [1806886] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:18.061 UTC [1806886] FATAL: connection to client lost
2022-12-11 12:36:18.320 UTC [1806938] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:18.320 UTC [1806938] FATAL: connection to client lost
2022-12-11 12:36:18.843 UTC [1807035] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:18.843 UTC [1807035] FATAL: connection to client lost
2022-12-11 12:36:19.209 UTC [1807113] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:19.209 UTC [1807113] FATAL: connection to client lost
2022-12-11 12:36:20.263 UTC [1807296] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:20.263 UTC [1807296] FATAL: connection to client lost
2022-12-11 12:36:21.356 UTC [1807495] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:21.356 UTC [1807495] FATAL: connection to client lost
2022-12-11 12:36:21.458 UTC [1807521] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:21.458 UTC [1807521] FATAL: connection to client lost
2022-12-11 12:36:22.489 UTC [1807708] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:22.489 UTC [1807708] FATAL: connection to client lost
2022-12-11 12:36:23.671 UTC [1807957] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:23.671 UTC [1807957] FATAL: connection to client lost
2022-12-11 12:36:23.748 UTC [1807970] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:23.748 UTC [1807970] FATAL: connection to client lost
2022-12-11 12:36:24.541 UTC [1807983] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:24.541 UTC [1807983] FATAL: connection to client lost
2022-12-11 12:36:24.702 UTC [1808144] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:24.702 UTC [1808144] FATAL: connection to client lost
2022-12-11 12:36:24.894 UTC [1808179] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:24.894 UTC [1808179] FATAL: connection to client lost
2022-12-11 12:36:25.774 UTC [1808478] FATAL: sorry, too many clients already
2022-12-11 12:36:25.776 UTC [1808477] FATAL: sorry, too many clients already
2022-12-11 12:36:25.776 UTC [1808479] FATAL: sorry, too many clients already
2022-12-11 12:36:25.778 UTC [1808485] FATAL: sorry, too many clients already
2022-12-11 12:36:25.779 UTC [1808487] FATAL: sorry, too many clients already
2022-12-11 12:36:25.796 UTC [1808498] FATAL: sorry, too many clients already
2022-12-11 12:36:26.413 UTC [1808565] FATAL: sorry, too many clients already
2022-12-11 12:36:26.561 UTC [1808566] FATAL: sorry, too many clients already
2022-12-11 12:36:26.711 UTC [1808567] FATAL: sorry, too many clients already
2022-12-11 12:36:27.001 UTC [1808568] FATAL: sorry, too many clients already
2022-12-11 12:36:27.345 UTC [1808574] FATAL: sorry, too many clients already
2022-12-11 12:36:27.461 UTC [1808575] FATAL: sorry, too many clients already
2022-12-11 12:36:27.569 UTC [1808576] FATAL: sorry, too many clients already
2022-12-11 12:36:27.653 UTC [1808577] FATAL: sorry, too many clients already
2022-12-11 12:36:27.811 UTC [1808578] FATAL: sorry, too many clients already
2022-12-11 12:36:28.213 UTC [1808584] LOG: could not send data to
client: Broken pipe
2022-12-11 12:36:28.213 UTC [1808584] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2022-12-11 12:36:29.403 UTC [1808585] LOG: could not receive data
from client: Connection reset by peer
2022-12-11 12:36:30.450 UTC [1632383] LOG: server process (PID
1739971) was terminated by signal 6: Aborted
2022-12-11 12:36:30.450 UTC [1632383] DETAIL: Failed process was
running: insert into sch18.pnt ( p ) values (
(select p from sch20.pnt_fdw limit 1 offset 79)
)
2022-12-11 12:36:30.450 UTC [1632383] LOG: terminating any other
active server processes
################################################
2022-11-30 12:27:27.523 UTC [271497] LOG: out of file descriptors:
Too many open files; release and retry
2022-11-30 12:27:27.523 UTC [271497] STATEMENT: update sch18.dt set
d = cast(nullif(sch18.dt.d,
sch18.dt.d) as date)
returning
pg_catalog.pg_client_encoding() as c0,
cast(coalesce(pg_catalog.pg_conf_load_time(),
case when pg_catalog.random() is NULL then
pg_catalog.pg_stat_get_last_autovacuum_time(
cast(pg_catalog.pg_my_temp_schema() as oid)) else
pg_catalog.pg_stat_get_last_autovacuum_time(
cast(pg_catalog.pg_my_temp_schema() as oid)) end
) as timestamptz) as c1,
pg_catalog.justify_interval(
cast(case when ((select f1 from public.invalid_check_con
limit 1 offset 5)
is not NULL)
or ((((select p from sch20.pnt_fdw limit 1 offset 71)
>^ (select p from sch30.pnt limit 1 offset 4)
)
or ((((select bitv from public.caster limit 1 offset 3)
<= (select bitv from public.caster limit
1 offset 4)
)
or ((false)
and (cast(null as name) ~~ (select t from
others.measurement_y1975_fdw limit 1 offset 5)
)))
or ((select home_base from public.slow_emp4000
limit 1 offset 6)
~= cast(null as box))))
or (((select pg_catalog.min(last_msg_send_time) from
pg_catalog.pg_stat_subscription)
> sch18.dt.t)
or (cast(null as xid) <> (select
pg_catalog.bit_or(i) from public.tstu)
))) then public.tstz_dist(
cast(cast(null as timestamptz) as timestamptz),
cast((select creation_time from pg_catalog.pg_cursors
limit 1 offset 4)
as timestamptz)) else public.tstz_dist(
cast(cast(null as timestamptz) as timestamptz),
cast((select creation_time from pg_catalog.pg_cursors
limit 1 offset 4)
as timestamptz)) end
as "interval")) as c2,
pg_catalog.json_build_object() as c3,
pg_catalog.pg_control_system() as c4,
pg_catalog.json_build_object() as c5,
pg_catalog.xpath(
cast(public.dblink_connect(
cast(pg_catalog.timeofday() as text),
cast(public.connection_parameters() as text)) as text),
cast(pg_catalog.query_to_xml(
cast(public.whoami() as text),
cast(pg_catalog.pg_jit_available() as bool),
cast(pg_catalog.pg_rotate_logfile() as bool),
cast(pg_catalog.pg_current_logfile() as text)) as xml)) as c6
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 430)
2022-11-30 12:27:28.001 UTC [271498] LOG: could not receive data from
client: Connection reset by peer
2022-11-30 12:27:28.905 UTC [221737] LOG: server process (PID 271497)
was terminated by signal 6: Aborted
2022-11-30 12:27:28.905 UTC [221737] DETAIL: Failed process was
running: update sch18.dt set
d = cast(nullif(sch18.dt.d,
sch18.dt.d) as date)
returning
pg_catalog.pg_client_encoding() as c0,
cast(coalesce(pg_catalog.pg_conf_load_time(),
case when pg_catalog.random() is NULL then
pg_catalog.pg_stat_get_last_autovacuum_time(
cast(pg_catalog.pg_my_temp_schema() as oid)) else
pg_catalog.pg_stat_get_last_autovacuum_time(
cast(pg_catalog.pg_my_temp_schema() as oid)) end
) as timestamptz) as c1,
pg_catalog.justify_interval(
cast(case when ((select f1 from public.invalid_check_con
limit 1 offset 5)
is not NULL)
or ((((select p from sch20.pnt_fdw limit 1 offset 71)
>^ (select p from sch30.pnt limit 1 offset 4)
)
or ((((select bitv from public.caster limit 1 offset 3)
<= (select bitv from public.caster limit
1 offset 4)
)
or ((false)
and (cast(null as name) ~~ (select t from
others.measurement_y1975_fd
2022-11-30 12:27:28.905 UTC [221737] LOG: terminating any other
active server processes
################################################
2022-11-22 13:44:04.604 UTC [1508667] LOG: could not send data to
client: Broken pipe
2022-11-22 13:44:04.604 UTC [1508667] FATAL: connection to client lost
2022-11-22 13:44:04.706 UTC [1508668] LOG: could not send data to
client: Broken pipe
2022-11-22 13:44:04.706 UTC [1508668] FATAL: connection to client lost
2022-11-22 13:44:05.374 UTC [1508675] LOG: could not send data to
client: Broken pipe
2022-11-22 13:44:05.374 UTC [1508675] FATAL: connection to client lost
2022-11-22 13:44:05.413 UTC [1508040] LOG: process 1508040 still
waiting for ShareLock on virtual transaction 513/212 after 5000.879 ms
2022-11-22 13:44:05.413 UTC [1508040] DETAIL: Process holding the
lock: 1508053. Wait queue: 1508033, 1508064, 1508038, 1508044,
1508040.
2022-11-22 13:44:05.413 UTC [1508040] STATEMENT: REINDEX INDEX
CONCURRENTLY sch7.chr_c_idx4;
2022-11-22 13:44:07.293 UTC [1508676] LOG: could not send data to
client: Broken pipe
2022-11-22 13:44:07.293 UTC [1508676] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-11-22 13:44:08.486 UTC [1508687] LOG: could not receive data
from client: Connection reset by peer
2022-11-22 13:44:09.724 UTC [1315578] LOG: server process (PID
1456482) was terminated by signal 6: Aborted
2022-11-22 13:44:09.724 UTC [1315578] DETAIL: Failed process was
running: select
subq_0.c2 as c0
from
sch20.dt as sample_0 tablesample system (9.8) ,
lateral (select
public.gen_random_uuid() as c0,
sample_1.r_id as c1,
pg_catalog.pg_notification_queue_usage() as c2,
17 as c3
from
others.measurement_y2021_fdw as ref_0
left join public.timetzcmp as sample_1 tablesample
system (6.5)
on (sample_0.d is NULL)
where (true)
or (case when false then cast(null as polygon) else
cast(null as polygon) end
~= (select polygon from public.tab_core_types
limit 1 offset 6)
)) as subq_0
where public.test_found() is not NULL
limit 109
2022-11-22 13:44:09.724 UTC [1315578] LOG: terminating any other
active server processes
################################################
2022-11-19 13:26:40.056 UTC [1484625] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:40.056 UTC [1484625] FATAL: connection to client lost
2022-11-19 13:26:40.399 UTC [1484628] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:40.399 UTC [1484628] FATAL: connection to client lost
2022-11-19 13:26:40.713 UTC [1484629] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:40.713 UTC [1484629] FATAL: connection to client lost
2022-11-19 13:26:41.601 UTC [1484635] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:41.601 UTC [1484635] FATAL: connection to client lost
2022-11-19 13:26:41.747 UTC [1484643] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:41.747 UTC [1484643] FATAL: connection to client lost
2022-11-19 13:26:41.917 UTC [1484644] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:41.917 UTC [1484644] FATAL: connection to client lost
2022-11-19 13:26:42.325 UTC [1484649] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:42.325 UTC [1484649] FATAL: connection to client lost
2022-11-19 13:26:42.476 UTC [1484652] LOG: could not send data to
client: Broken pipe
2022-11-19 13:26:42.476 UTC [1484652] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-11-19 13:26:43.703 UTC [1484658] LOG: could not receive data
from client: Connection reset by peer
2022-11-19 13:26:45.109 UTC [1484353] LOG: process 1484353 still
waiting for ShareLock on virtual transaction 760/55 after 5001.582 ms
2022-11-19 13:26:45.109 UTC [1484353] DETAIL: Process holding the
lock: 1484351. Wait queue: 1484353.
2022-11-19 13:26:45.109 UTC [1484353] STATEMENT: REINDEX INDEX
CONCURRENTLY sch11.pnt_p_idx;
2022-11-19 13:26:45.161 UTC [1484627] LOG: process 1484627 still
waiting for ShareLock on virtual transaction 1065/47 after 5002.366 ms
2022-11-19 13:26:45.161 UTC [1484627] DETAIL: Process holding the
lock: 1484357. Wait queue: 1484627, 1484637, 1484651, 1484648.
2022-11-19 13:26:45.161 UTC [1484627] STATEMENT: REINDEX INDEX
CONCURRENTLY sch25.txt_t_idx;
2022-11-19 13:26:45.749 UTC [1379904] LOG: server process (PID
1447940) was terminated by signal 6: Aborted
2022-11-19 13:26:45.749 UTC [1379904] DETAIL: Failed process was
running: select
pg_catalog.getdatabaseencoding() as c0,
case when pg_catalog.statement_timestamp() is not NULL then
pg_catalog.pg_get_function_arguments(
cast(cast(null as oid) as oid)) else
pg_catalog.pg_get_function_arguments(
cast(cast(null as oid) as oid)) end
as c1,
public.test_found() as c2,
ref_0.n as c3,
ref_0.n as c4,
public.myaggn08b(
cast(ref_0.n as "numeric")) over (partition by ref_0.n
order by ref_0.n) as c5,
35 as c6,
pg_catalog.pg_my_temp_schema() as c7,
pg_catalog.json_build_array() as c8,
pg_catalog.pg_my_temp_schema() as c9,
pg_catalog.jsonb_build_object() as c10,
public.make_table() as c11,
91 as c12,
public.int8alias1in(
cast(pg_catalog.timetztypmodout(
cast(
pg_catalog.bit_or(
cast(8 as int4)) over (partition by ref_0.n order by
ref_0.n) as int4)) as cstring)) as c13,
pg_catalog.pg_replication_origin_session_is_setup() as c14
from
sch18.num_fdw as ref_0
where pg_catalog.inet_client_port() ===
2022-11-19 13:26:45.749 UTC [1379904] LOG: terminating any other
active server processes
################################################
2022-10-10 12:46:01.941 UTC [887918] LOG: could not send data to
client: Broken pipe
2022-10-10 12:46:01.941 UTC [887918] FATAL: connection to client lost
2022-10-10 12:46:11.034 UTC [889217] LOG: could not send data to
client: Broken pipe
2022-10-10 12:46:11.034 UTC [889217] FATAL: connection to client lost
2022-10-10 12:46:14.295 UTC [889711] LOG: could not send data to
client: Broken pipe
2022-10-10 12:46:14.295 UTC [889711] FATAL: connection to client lost
2022-10-10 12:46:27.973 UTC [891019] LOG: could not send data to
client: Broken pipe
2022-10-10 12:46:27.973 UTC [891019] FATAL: connection to client lost
2022-10-10 12:46:28.952 UTC [891384] LOG: could not send data to
client: Broken pipe
2022-10-10 12:46:28.952 UTC [891384] FATAL: connection to client lost
TRAP: FailedAssertion("!(((allPgXact[proc->pgprocno].xid) !=
((TransactionId) 0)))", File: "procarray.c", Line: 419)
2022-10-10 12:46:34.414 UTC [889798] LOG: could not receive data from
client: Connection reset by peer
2022-10-10 12:46:35.496 UTC [872082] LOG: server process (PID 889797)
was terminated by signal 6: Aborted
2022-10-10 12:46:35.496 UTC [872082] DETAIL: Failed process was
running: update t set
a = t.a
returning
cast(public.dblink_connect(
cast(pg_catalog.timeofday() as text),
cast('dbname=''postgres'' port=54321' as text)) as text) as c0,
(select b from s_fdw limit 1 offset 6) as c15
;
2022-10-10 12:46:35.496 UTC [872082] LOG: terminating any other
active server processes
################################################
-
robins
Hi,
On 2023-02-15 14:46:13 +1030, Robins Tharakan wrote:
> Thanks for taking a look and possibly you're correct with your
> assumption. I mean I see a ton of FATALs but let me know if I am
> mistaken in assuming them to be harmless (since they just convey that
> the client's gone away)?
Those are indeed not very interesting - although it'd be interesting to know
what caused the clients to go away.
> Nonetheless, I have provided error logs going back till Oct 22 just in
> case the engine can recover from some of those scenarios. Two things
> about the test scenario that may be relevant:
>
> 1. Since performance was the least of my worries, the postgres server
> and the client workload are on the same box. Add dblink / FDW to this
> mix, and it is easy to end up with a ton of loopback connections
> (think SELECT dblink_conect() FROM pg_catalog.pg_class) - IMO
> noteworthy, since there are a ton of "Broken pipe"s and one instance
> of 'too many file descriptors'.
I think the "too many file descriptors" bit might be the interesting part.
I suspect the reason you're not seeing this on newer versions is that 13+ has
commit 3d475515a15f70a4a3f36fbbba93db6877ff8346
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date: 2020-02-24 17:28:33 -0500
Account explicitly for long-lived FDs that are allocated outside fd.c.
But I can't yet explain precisely why that causes the assertion failures. A
vague guess is that we fail to write 2PC state files due to the lack of FD
accounting, throw an error due to that, and then fail with that assert during
handling the error.
It might be worth trying to reproduce the issue with a much lower ulimit -S
-n, to reach the problematic state more quickly. A reproducer would be very
useufl.
> 2. All versions are subjected to similar workload and it is possible
> that v13+ has generally improved in this area, and thus this possibly
> crashes less? Unsure.
What range of versions / commits are you testing this workload on?
Are you testing 11 as well? Because I don't see why we'd have the issue on 12,
but not 11.
Greetings,
Andres Freund
Hi, On Wed, 15 Feb 2023 at 15:36, Andres Freund <andres@anarazel.de> wrote: > > What range of versions / commits are you testing this workload on? > Are you testing 11 as well? Because I don't see why we'd have the issue on 12, > but not 11. My bad, should have explained this upfront. The tests I run are *always* on STABLE (or master). IIRC I had encountered an error in v10 / v11 and had disabled testing those majors. Since currently, I am only testing v12+, this may exist in previous major versions, just not visible in my testing. > It might be worth trying to reproduce the issue with a much lower ulimit -S > -n, to reach the problematic state more quickly. A reproducer would be very > useful.... Those are indeed not very interesting - although it'd be interesting > to know what caused the clients to go away. I am travelling the coming few weeks, but would keep this in mind and revert once I have something to share. - robins