Re: Deadlock in XLogInsert at AIX

From: Konstantin Knizhnik <k(dot)knizhnik(at)postgrespro(dot)ru>
To: pgsql-hackers(at)postgresql(dot)org
Cc: Heikki Linnakangas <hlinnaka(at)iki(dot)fi>
Subject: Re: Deadlock in XLogInsert at AIX
Date: 2017-02-02 08:05:39
Message-ID: d31bb3f3-d5ef-603d-730a-1e499f21f223@postgrespro.ru
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Last update on the issue with deadlock in XLogInsert.

After almost one day of working, pgbench is once again not working
normally:(
There are no deadlock, there are no core files and no error messages in log.
But TPS is almost zero:

progress: 57446.0 s, 1.1 tps, lat 3840.265 ms stddev NaNQ
progress: 57447.3 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57448.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57449.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57450.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57451.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57452.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57453.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57454.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57455.1 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57456.5 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57457.1 s, 164.6 tps, lat 11504.085 ms stddev 5902.148
progress: 57458.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57459.0 s, 234.0 tps, lat 1597.573 ms stddev 3665.814
progress: 57460.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57461.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57462.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57463.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57464.0 s, 602.8 tps, lat 906.765 ms stddev 1940.256
progress: 57465.0 s, 7.2 tps, lat 38.052 ms stddev 12.302
progress: 57466.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57467.1 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57468.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57469.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57470.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57471.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57472.1 s, 147.8 tps, lat 4379.790 ms stddev 3431.477
progress: 57473.0 s, 1314.1 tps, lat 156.884 ms stddev 535.761
progress: 57474.0 s, 1272.2 tps, lat 31.548 ms stddev 59.538
progress: 57475.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57476.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57477.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57478.0 s, 1688.6 tps, lat 268.379 ms stddev 956.537
progress: 57479.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57480.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57481.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57482.1 s, 29.0 tps, lat 3500.432 ms stddev 54.177
progress: 57483.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57484.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57485.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57486.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57487.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57488.0 s, 66.0 tps, lat 9813.646 ms stddev 19.807
progress: 57489.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57490.0 s, 31.0 tps, lat 8368.125 ms stddev 933.997
progress: 57491.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57492.0 s, 1601.0 tps, lat 226.865 ms stddev 844.952
progress: 57493.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ
progress: 57494.0 s, 0.0 tps, lat NaNQ ms stddev -NaNQ

ps auwx shows the following picture:
[10:44:12]postgres(at)postgres:~/postgresql $ ps auwx | fgrep postgres
postgres 61802470 0.4 0.0 4064 4180 pts/6 A 18:54:58 976:56
pgbench -c 100 -j 20 -P 1 -T 1000000000 -p 5436
postgres 15271518 0.0 0.0 138276 15024 - A 10:43:34 0:06
postgres: autovacuum worker process postgres
postgres 13305354 0.0 0.0 22944 21356 - A 20:49:04 27:51
postgres: autovacuum worker process postgres
postgres 5245902 0.0 0.0 14072 14020 - A 18:54:59 10:24
postgres: postgres postgres [local] COMMIT
postgres 44303278 0.0 0.0 15176 14036 - A 18:54:59 10:18
postgres: postgres postgres [local] COMMIT
postgres 38601340 0.0 0.0 11564 14008 - A 18:54:59 10:16
postgres: postgres postgres [local] COMMIT
postgres 53674890 0.0 0.0 12712 14004 - A 18:54:59 8:54
postgres: postgres postgres [local] COMMIT
postgres 27591640 0.0 0.0 15040 14028 - A 18:54:59 8:38
postgres: postgres postgres [local] COMMIT
postgres 40960422 0.0 0.0 12128 13996 - A 18:54:59 8:36
postgres: postgres postgres [local] COMMIT
postgres 41288514 0.0 0.0 10544 14012 - A 18:54:59 8:30
postgres: postgres postgres [local] idle
postgres 55771564 0.0 0.0 12844 14008 - A 18:54:59 8:24
postgres: postgres postgres [local] COMMIT
postgres 21760842 0.0 0.0 13164 14008 - A 18:54:59 8:17
postgres: postgres postgres [local] COMMIT
postgres 18810974 0.0 0.0 10416 14012 - A 18:54:59 8:13
postgres: postgres postgres [local] idle in transaction
postgres 17566474 0.0 0.0 10224 14012 - A 18:54:59 8:02
postgres: postgres postgres [local] COMMIT
postgres 63963402 0.0 0.0 11300 14000 - A 18:54:59 7:48
postgres: postgres postgres [local] COMMIT
postgres 9963962 0.0 0.0 15548 14024 - A 18:54:59 7:37
postgres: postgres postgres [local] idle
postgres 10094942 0.0 0.0 12192 13996 - A 18:54:59 7:33
postgres: postgres postgres [local] COMMIT
postgres 53740662 0.0 0.0 15104 14028 - A 18:54:59 7:33
postgres: postgres postgres [local] idle
postgres 42926266 0.0 0.0 15352 14020 - A 18:54:59 7:32
postgres: postgres postgres [local] COMMIT
postgres 29295244 0.0 0.0 10612 14016 - A 18:54:59 7:31
postgres: postgres postgres [local] idle in transaction
postgres 4392458 0.0 0.0 11504 14012 - A 18:54:59 7:28
postgres: postgres postgres [local] COMMIT
postgres 45482810 0.0 0.0 9896 14004 - A 18:54:59 7:27
postgres: postgres postgres [local] COMMIT
postgres 59703706 0.0 0.0 11384 14020 - A 18:54:59 7:26
postgres: postgres postgres [local] COMMIT
postgres 13697320 0.0 0.0 13556 14016 - A 18:54:59 7:26
postgres: postgres postgres [local] COMMIT
postgres 65275126 0.0 0.0 13748 14016 - A 18:54:59 7:24
postgres: postgres postgres [local] COMMIT
postgres 17435626 0.0 0.0 13492 14016 - A 18:54:59 7:23
postgres: postgres postgres [local] COMMIT
postgres 32834044 0.0 0.0 9648 14012 - A 18:54:59 7:23
postgres: postgres postgres [local] idle in transaction
postgres 3015796 0.0 0.0 15292 14024 - A 18:54:59 7:22
postgres: postgres postgres [local] COMMIT
postgres 54789310 0.0 0.0 15480 14020 - A 18:54:59 7:21
postgres: postgres postgres [local] COMMIT
postgres 13369644 0.0 0.0 13300 14016 - A 18:54:59 7:20
postgres: postgres postgres [local] COMMIT
postgres 49415352 0.0 0.0 12392 14004 - A 18:54:59 7:19
postgres: postgres postgres [local] COMMIT
postgres 11273960 0.0 0.0 12328 14004 - A 18:54:59 7:19
postgres: postgres postgres [local] COMMIT
postgres 37749126 0.0 0.0 13628 14024 - A 18:54:59 7:17
postgres: postgres postgres [local] COMMIT
postgres 42664990 0.0 0.0 14012 14024 - A 18:54:59 7:16
postgres: postgres postgres [local] idle
postgres 48628314 0.0 0.0 12972 14008 - A 18:54:59 7:15
postgres: postgres postgres [local] COMMIT
postgres 27526940 0.0 0.0 9832 14004 - A 18:54:59 7:15
postgres: postgres postgres [local] COMMIT
postgres 4262142 0.0 0.0 11048 14004 - A 18:54:59 7:14
postgres: postgres postgres [local] COMMIT
postgres 59049404 0.0 0.0 14200 14020 - A 18:54:59 7:13
postgres: postgres postgres [local] COMMIT
postgres 25035818 0.0 0.0 9264 14012 - A 18:54:59 7:11
postgres: postgres postgres [local] COMMIT
postgres 62587380 0.0 0.0 15420 14024 - A 18:54:59 7:10
postgres: postgres postgres [local] COMMIT
postgres 66848122 0.0 0.0 12588 14008 - A 18:54:59 7:06
postgres: postgres postgres [local] COMMIT
postgres 45352748 0.0 0.0 14912 14028 - A 18:54:59 7:04
postgres: postgres postgres [local] UPDATE waiting
postgres 46990366 0.0 0.0 11680 13996 - A 18:54:59 7:03
postgres: postgres postgres [local] idle
postgres 42271516 0.0 0.0 14776 14020 - A 18:54:59 6:59
postgres: postgres postgres [local] COMMIT
postgres 43253972 0.0 0.0 9192 14004 - A 18:54:59 6:59
postgres: postgres postgres [local] UPDATE waiting
postgres 37487324 0.0 0.0 11936 13996 - A 18:54:59 6:58
postgres: postgres postgres [local] COMMIT
postgres 33096324 0.0 0.0 14396 14024 - A 18:54:59 6:58
postgres: postgres postgres [local] COMMIT
postgres 37094658 0.0 0.0 11184 14012 - A 18:54:59 6:57
postgres: postgres postgres [local] UPDATE waiting
postgres 41223048 0.0 0.0 11628 14008 - A 18:54:59 6:57
postgres: postgres postgres [local] idle in transaction
postgres 13240806 0.0 0.0 10024 14004 - A 18:54:59 6:57
postgres: postgres postgres [local] COMMIT
postgres 61276560 0.0 0.0 10728 14004 - A 18:54:59 6:56
postgres: postgres postgres [local] COMMIT
postgres 66585476 0.0 0.0 12908 14008 - A 18:54:59 6:52
postgres: postgres postgres [local] UPDATE waiting
postgres 15074434 0.0 0.0 9328 14012 - A 18:54:59 6:50
postgres: postgres postgres [local] COMMIT
postgres 33751620 0.0 0.0 12456 14004 - A 18:54:59 6:47
postgres: postgres postgres [local] COMMIT
postgres 854400 0.0 0.0 14584 14020 - A 18:54:59 6:46
postgres: postgres postgres [local] COMMIT
postgres 36504484 0.0 0.0 14264 14020 - A 18:54:59 6:46
postgres: postgres postgres [local] COMMIT
postgres 61408076 0.0 0.0 11112 14004 - A 18:54:59 6:46
postgres: postgres postgres [local] COMMIT
postgres 24905384 0.0 0.0 14712 14020 - A 18:54:59 6:45
postgres: postgres postgres [local] COMMIT
postgres 61867150 0.0 0.0 13812 14016 - A 18:54:59 6:45
postgres: postgres postgres [local] COMMIT
postgres 38798230 0.0 0.0 13876 14016 - A 18:54:59 6:45
postgres: postgres postgres [local] COMMIT
postgres 53217076 0.0 0.0 13228 14008 - A 18:54:59 6:43
postgres: postgres postgres [local] COMMIT
postgres 19727378 0.0 0.0 9456 14012 - A 18:54:59 6:40
postgres: postgres postgres [local] idle in transaction
postgres 20253128 0.0 0.0 12648 14004 - A 18:54:59 6:38
postgres: postgres postgres [local] COMMIT
postgres 35784016 0.0 0.0 10088 14004 - A 18:54:59 6:38
postgres: postgres postgres [local] COMMIT
postgres 9243026 0.0 0.0 13100 14008 - A 18:54:59 6:37
postgres: postgres postgres [local] COMMIT
postgres 14027754 0.0 0.0 10792 14004 - A 18:54:59 6:35
postgres: postgres postgres [local] COMMIT
postgres 61342300 0.0 0.0 12264 14004 - A 18:54:59 6:34
postgres: postgres postgres [local] UPDATE waiting
postgres 21693262 0.0 0.0 14460 14024 - A 18:54:59 6:30
postgres: postgres postgres [local] COMMIT
postgres 53938020 0.0 0.0 10856 14004 - A 18:54:59 6:30
postgres: postgres postgres [local] COMMIT
postgres 24053688 0.0 0.0 12064 13996 - A 18:54:59 6:29
postgres: postgres postgres [local] COMMIT
postgres 45024698 0.0 0.0 14984 14036 - A 18:54:59 6:25
postgres: postgres postgres [local] COMMIT
postgres 20710448 0.0 0.0 10480 14012 - A 18:54:59 6:24
postgres: postgres postgres [local] COMMIT
postgres 8718716 0.0 0.0 15232 14028 - A 18:54:59 6:23
postgres: postgres postgres [local] COMMIT
postgres 55313538 0.0 0.0 14136 14020 - A 18:54:59 6:22
postgres: postgres postgres [local] COMMIT
postgres 13896472 0.0 0.0 9584 14012 - A 18:54:59 6:18
postgres: postgres postgres [local] COMMIT
postgres 8261178 0.0 0.0 9960 14004 - A 18:54:59 6:18
postgres: postgres postgres [local] COMMIT
postgres 8980574 0.0 0.0 10540 15608 - A 18:54:54 6:17
postgres: checkpointer process
postgres 4787946 0.0 0.0 9392 14012 - A 18:54:59 6:16
postgres: postgres postgres [local] COMMIT
postgres 27919600 0.0 0.0 11812 14000 - A 18:54:59 6:16
postgres: postgres postgres [local] COMMIT
postgres 47579896 0.0 0.0 10920 14004 - A 18:54:59 6:14
postgres: postgres postgres [local] COMMIT
postgres 10290864 0.0 0.0 10160 14012 - A 18:54:59 6:13
postgres: postgres postgres [local] COMMIT
postgres 46072384 0.0 0.0 14520 14020 - A 18:54:59 6:13
postgres: postgres postgres [local] COMMIT
postgres 57737434 0.0 0.0 9520 14012 - A 18:54:59 6:12
postgres: postgres postgres [local] COMMIT
postgres 65012512 0.0 0.0 9768 14004 - A 18:54:59 6:11
postgres: postgres postgres [local] COMMIT
postgres 21495924 0.0 0.0 12000 13996 - A 18:54:59 6:11
postgres: postgres postgres [local] COMMIT
postgres 59704720 0.0 0.0 14656 14028 - A 18:54:59 6:09
postgres: postgres postgres [local] COMMIT
postgres 58458128 0.0 0.0 13036 14008 - A 18:54:59 6:08
postgres: postgres postgres [local] COMMIT
postgres 53412068 0.0 0.0 13684 14016 - A 18:54:59 6:02
postgres: postgres postgres [local] COMMIT
postgres 8652638 0.0 0.0 11244 14008 - A 18:54:59 6:00
postgres: postgres postgres [local] COMMIT
postgres 14289464 0.0 0.0 10672 14012 - A 18:54:59 6:00
postgres: postgres postgres [local] COMMIT
postgres 16582572 0.0 0.0 14328 14020 - A 18:54:59 5:56
postgres: postgres postgres [local] COMMIT
postgres 9308408 0.0 0.0 9704 14004 - A 18:54:59 5:56
postgres: postgres postgres [local] COMMIT
postgres 51970736 0.0 0.0 11440 14012 - A 18:54:59 5:51
postgres: postgres postgres [local] COMMIT
postgres 19792490 0.0 0.0 13364 14016 - A 18:54:59 5:48
postgres: postgres postgres [local] COMMIT
postgres 58065970 0.0 0.0 11744 13996 - A 18:54:59 5:38
postgres: postgres postgres [local] COMMIT
postgres 17891344 0.0 0.0 10984 14004 - A 18:54:59 5:33
postgres: postgres postgres [local] COMMIT
postgres 20121588 0.0 0.0 12520 14004 - A 18:54:59 5:30
postgres: postgres postgres [local] COMMIT
postgres 39977868 0.0 0.0 13944 14020 - A 18:54:59 5:26
postgres: postgres postgres [local] COMMIT
postgres 25167604 0.0 0.0 11872 13996 - A 18:54:59 5:25
postgres: postgres postgres [local] COMMIT
postgres 22348378 0.0 0.0 10352 14012 - A 18:54:59 5:25
postgres: postgres postgres [local] COMMIT
postgres 8587156 0.0 0.0 12780 14008 - A 18:54:59 5:21
postgres: postgres postgres [local] COMMIT
postgres 12453402 0.0 0.0 10288 14012 - A 18:54:59 5:20
postgres: postgres postgres [local] COMMIT
postgres 25822956 0.0 0.0 13428 14016 - A 18:54:59 5:04
postgres: postgres postgres [local] COMMIT
postgres 7145012 0.0 0.0 14844 14024 - A 18:54:59 5:04
postgres: postgres postgres [local] COMMIT
postgres 10224292 0.0 0.0 8100 13040 - A 18:54:54 2:55
postgres: wal writer process
postgres 47711172 0.0 0.0 8080 13084 - A 18:54:54 0:57
postgres: writer process
postgres 22743474 0.0 0.0 8328 13204 - A 18:54:54 0:29
postgres: stats collector process
postgres 1706138 0.0 0.0 137280 12940 pts/6 A 18:54:54 0:17
/opt/postgresql/xlc-debug/9.6/bin/postgres -D xlc-debug
postgres 9898070 0.0 0.0 8528 13404 - A 18:54:54 0:02
postgres: autovacuum launcher process
postgres 55444330 0.0 0.0 7884 13016 - A 18:54:54 0:01
postgres: logger process
postgres 42927172 0.0 0.0 138232 13892 - A 10:44:18 0:00
postgres: autovacuum worker process postgres
postgres 3934886 0.0 0.0 244 256 pts/3 A 10:44:21 0:00 fgrep
postgres

which is pericodically (but slowly) updated. So there seems to be no
hanged backends (it is hard to inspect state of all 100 backends).
CPU activity is almost zero as well as disk activity, memory is mostly
free, ...

Attaching to one of the backends I got the following stack traces in
debugger:

[10:44:21]postgres(at)postgres:~/postgresql $ dbx -a 25822956
/opt/postgresql/xlc-debug/9.6/bin/postgres
Waiting to attach to process 25822956 ...
Successfully attached to postgres.
warning: Directory containing postgres could not be determined.
Apply 'use' command to initialize source path.

Type 'help' for help.
reading symbolic information ...warning: no source compiled with -g

stopped in __fd_poll at 0x9000000001545d4
0x9000000001545d4 (__fd_poll+0xb4) e8410028 ld r2,0x28(r1)
(dbx) where
__fd_poll(??, ??, ??) at 0x9000000001545d4
WaitEventSetWait() at 0x10012b730
secure_read() at 0x100141ca4
IPRA.$pq_recvbuf() at 0x10013e370
pq_getbyte() at 0x10013f294
SocketBackend() at 0x10006cf98
postgres.IPRA.$exec_simple_query.ReadCommand() at 0x10006cf1c
PostgresMain() at 0x10006e590
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) cont
^C
Interrupt in semop at 0x9000000001f5790
0x9000000001f5790 (semop+0xb0) e8410028 ld r2,0x28(r1)
(dbx) where
semop(??, ??, ??) at 0x9000000001f5790
PGSemaphoreLock() at 0x100049040
LWLockAcquireOrWait() at 0x100047140
XLogFlush() at 0x1000e89ec
RecordTransactionCommit() at 0x10005856c
xact.RecordTransactionAbort.IPRA.$CommitTransaction() at 0x10005a598
CommitTransactionCommand() at 0x10005ea30
postgres.IPRA.$exec_describe_portal_message.IPRA.$finish_xact_command()
at 0x10006c91c
IPRA.$exec_simple_query() at 0x10006c298
PostgresMain() at 0x10006eac0
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) cont
^C
Interrupt in __fd_poll at 0x9000000001545d4
0x9000000001545d4 (__fd_poll+0xb4) e8410028 ld r2,0x28(r1)
(dbx) where
__fd_poll(??, ??, ??) at 0x9000000001545d4
WaitEventSetWait() at 0x10012b730
WaitLatchOrSocket() at 0x10012b48c
ProcSleep() at 0x100144fe4
IPRA.$WaitOnLock() at 0x1001492fc
LockAcquireExtended() at 0x1001519ec
XactLockTableWait() at 0x10016d7e8
heap_update() at 0x1000cc7e4
IPRA.$ExecUpdate() at 0x1004f041c
ExecModifyTable() at 0x1004f2220
ExecProcNode() at 0x1001faf08
IPRA.$ExecutePlan() at 0x1001f64b0
standard_ExecutorRun() at 0x1001f9c34
ExecutorRun() at 0x1001f9d6c
pquery.IPRA.$FillPortalStore.IPRA.$ProcessQuery() at 0x1003309e4
IPRA.$PortalRunMulti() at 0x10032fcf8
PortalRun() at 0x100331030
IPRA.$exec_simple_query() at 0x10006c014
PostgresMain() at 0x10006eac0
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) cont

User defined signal 1 in __fd_poll at 0x9000000001545d4
0x9000000001545d4 (__fd_poll+0xb4) e8410028 ld r2,0x28(r1)
(dbx) where
__fd_poll(??, ??, ??) at 0x9000000001545d4
WaitEventSetWait() at 0x10012b730
WaitLatchOrSocket() at 0x10012b48c
ProcSleep() at 0x100144fe4
IPRA.$WaitOnLock() at 0x1001492fc
LockAcquireExtended() at 0x1001519ec
XactLockTableWait() at 0x10016d7e8
heap_update() at 0x1000cc7e4
IPRA.$ExecUpdate() at 0x1004f041c
ExecModifyTable() at 0x1004f2220
ExecProcNode() at 0x1001faf08
IPRA.$ExecutePlan() at 0x1001f64b0
standard_ExecutorRun() at 0x1001f9c34
ExecutorRun() at 0x1001f9d6c
pquery.IPRA.$FillPortalStore.IPRA.$ProcessQuery() at 0x1003309e4
IPRA.$PortalRunMulti() at 0x10032fcf8
PortalRun() at 0x100331030
IPRA.$exec_simple_query() at 0x10006c014
PostgresMain() at 0x10006eac0
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) cont

Broken pipe in send at 0x90000000010cfb4
0x90000000010cfb4 (send+0x2b4) e8410028 ld r2,0x28(r1)
(dbx) where
send(??, ??, ??, ??) at 0x90000000010cfb4
secure_write() at 0x100141a94
IPRA.$internal_flush() at 0x10013e800
socket_flush() at 0x10013ee7c
ReadyForQuery(at)AF106_4() at 0x10033241c
PostgresMain() at 0x10006eb7c
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) where
send(??, ??, ??, ??) at 0x90000000010cfb4
secure_write() at 0x100141a94
IPRA.$internal_flush() at 0x10013e800
socket_flush() at 0x10013ee7c
ReadyForQuery(at)AF106_4() at 0x10033241c
PostgresMain() at 0x10006eb7c
IPRA.$BackendRun() at 0x1001301ac
BackendStartup() at 0x10012f784
postmaster.IPRA.$do_start_bgworker.IPRA.$ServerLoop() at 0x10012fec4
PostmasterMain() at 0x100134760
main() at 0x1000006ac
(dbx) cont

execution completed (exit code 1)
(dbx) quit
^C
(dbx) quit
libdebug assertion "(rc == DB_SUCCESS)" failed at line 162 in file
../../../../../../../../../../../src/bos/usr/ccs/lib/libdbx/libdebug/modules/procdebug/ptrace/procdb_PtraceSession.C

I have no idea what's going on. It is release version without debug
information, assert checks and lwlock info. So it is hard to debug it.
Heikki, I will be pleased if you have a chance to login at the system
and look at it yourself.
May be you will have some idea what's happening...

Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Andrew Dunstan 2017-02-02 08:38:47 Re: Improvements in psql hooks for variables
Previous Message Michael Paquier 2017-02-02 06:34:33 Re: [BUGS] Bug in Physical Replication Slots (at least 9.5)?