Thread: crash while decoding INSERT ON CONFLICT

crash while decoding INSERT ON CONFLICT

From
Euler Taveira
Date:
Hi,

I got the following backtrace in a logical replication setup using 10.3.

Program terminated with signal 11, Segmentation fault.
#0  ReorderBufferCommit (rb=0xde2a08, xid=<value optimized out>,
commit_lsn=6211559254952, end_lsn=<value optimized out>,
commit_time=<value optimized out>, origin_id=<value optimized out>,
    origin_lsn=0) at reorderbuffer.c:1397
1397                                            change->action =
REORDER_BUFFER_CHANGE_INSERT;
Missing separate debuginfos, use: debuginfo-install
glibc-2.12-1.209.el6_9.2.x86_64 libxml2-2.7.6-21.el6_8.1.x86_64
zlib-1.2.3-29.el6.x86_64
(gdb) bt
#0  ReorderBufferCommit (rb=0xde2a08, xid=<value optimized out>,
commit_lsn=6211559254952, end_lsn=<value optimized out>,
commit_time=<value optimized out>, origin_id=<value optimized out>,
    origin_lsn=0) at reorderbuffer.c:1397
#1  0x00000000006bdd58 in DecodeCommit (ctx=0xdbe888, record=<value
optimized out>) at decode.c:611
#2  DecodeXactOp (ctx=0xdbe888, record=<value optimized out>) at decode.c:241
#3  LogicalDecodingProcessRecord (ctx=0xdbe888, record=<value
optimized out>) at decode.c:113
#4  0x00000000006d0754 in XLogSendLogical () at walsender.c:2781
#5  0x00000000006cf782 in WalSndLoop (send_data=0x6d0700
<XLogSendLogical>) at walsender.c:2149
#6  0x00000000006d1463 in StartLogicalReplication (cmd_string=<value
optimized out>) at walsender.c:1102
#7  exec_replication_command (cmd_string=<value optimized out>) at
walsender.c:1539
#8  0x00000000007182b9 in PostgresMain (argc=<value optimized out>,
argv=<value optimized out>, dbname=0xd368a8 "foo", username=<value
optimized out>) at postgres.c:4084
#9  0x00000000006ad27d in BackendRun (argc=<value optimized out>,
argv=<value optimized out>) at postmaster.c:4405
#10 BackendStartup (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:4077
#11 ServerLoop (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:1755
#12 PostmasterMain (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:1363
#13 0x000000000062e5b0 in main (argc=3, argv=0xd04540) at main.c:228
(gdb) p change
$1 = (ReorderBufferChange *) 0x0
(gdb) p specinsert
$2 = (ReorderBufferChange *) 0x0

If my math is correct the lsn 6211559254952 is 5A6/3DC86BA8. The transaction is:

rmgr: Btree       len (rec/tot):   3795/ 11731, tx:  144441221, lsn:
5A6/3DC80B58, prev 5A6/3DC80B28, desc: SPLIT_R level 0, firstright
139, blkref #0: rel 1663/355309/54931968 blk 176078, blkref #1: rel
1663/355309/54931968 blk 223615, blkref #2: rel 1663/355309/54931968
blk 176079 FPW
rmgr: Btree       len (rec/tot):     61/  4481, tx:  144441221, lsn:
5A6/3DC83948, prev 5A6/3DC80B58, desc: INSERT_UPPER off 39, blkref #0:
rel 1663/355309/54931968 blk 176062 FPW, blkref #1: rel
1663/355309/54931968 blk 176078
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC84AE8, prev 5A6/3DC83948, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/57252673 blk 218754
rmgr: Btree       len (rec/tot):     53/  7613, tx:  144441221, lsn:
5A6/3DC84B30, prev 5A6/3DC84AE8, desc: INSERT_LEAF off 129, blkref #0:
rel 1663/355309/57252674 blk 23008 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC86908, prev 5A6/3DC84B30, desc: INSERT_LEAF off 71, blkref #0:
rel 1663/355309/57252998 blk 156099
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC86948, prev 5A6/3DC86908, desc: INSERT_LEAF off 210, blkref #0:
rel 1663/355309/57253000 blk 219630
rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
5A6/3DC86990, prev 5A6/3DC86948, desc: HEAP_CONFIRM off 5, blkref #0:
rel 1663/355309/382872 blk 5520503
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC869C0, prev 5A6/3DC86990, desc: LOCK off 8: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42286702
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC869F8, prev 5A6/3DC869C0, desc: LOCK off 1: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42323652
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC86A30, prev 5A6/3DC869F8, desc: LOCK off 23: xid 144441221:
flags 0 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/355309/382874 blk
4688787
rmgr: Heap        len (rec/tot):    211/   211, tx:  144441221, lsn:
5A6/3DC86A68, prev 5A6/3DC86A30, desc: HOT_UPDATE off 23 xmax
144441221 ; new off 24 xmax 144441221, blkref #0: rel
1663/355309/382874 blk 4688787
rmgr: Heap        len (rec/tot):     98/    98, tx:  144441221, lsn:
5A6/3DC86B40, prev 5A6/3DC86A68, desc: HOT_UPDATE off 32 xmax
144441221 ; new off 34 xmax 0, blkref #0: rel 1663/355309/39370447 blk
6284
rmgr: Transaction len (rec/tot):     46/    46, tx:  144441221, lsn:
5A6/3DC86BA8, prev 5A6/3DC86B40, desc: COMMIT 2018-05-21
10:26:05.830168 -03

which translates into something like:

BEGIN
INSERT INTO table_a ON CONFLICT
UPDATE table_b
UPDATE table_c
COMMIT

I don't have a test case yet. This is my next step after this report.
However, it seems to be related to INSERT ON CONFLICT decoding. Ideas?


-- 
   Euler Taveira                                   Timbira -
http://www.timbira.com.br/
   PostgreSQL: Consultoria, Desenvolvimento, Suporte 24x7 e Treinamento


Re: crash while decoding INSERT ON CONFLICT

From
Andres Freund
Date:
Hi,

On 2018-05-21 12:52:09 -0300, Euler Taveira wrote:
> Hi,
> 
> I got the following backtrace in a logical replication setup using 10.3.
> 
> Program terminated with signal 11, Segmentation fault.
> #0  ReorderBufferCommit (rb=0xde2a08, xid=<value optimized out>,
> commit_lsn=6211559254952, end_lsn=<value optimized out>,
> commit_time=<value optimized out>, origin_id=<value optimized out>,
>     origin_lsn=0) at reorderbuffer.c:1397
> 1397                                            change->action =
> REORDER_BUFFER_CHANGE_INSERT;
> Missing separate debuginfos, use: debuginfo-install
> glibc-2.12-1.209.el6_9.2.x86_64 libxml2-2.7.6-21.el6_8.1.x86_64
> zlib-1.2.3-29.el6.x86_64
> (gdb) bt
> #0  ReorderBufferCommit (rb=0xde2a08, xid=<value optimized out>,
> commit_lsn=6211559254952, end_lsn=<value optimized out>,
> commit_time=<value optimized out>, origin_id=<value optimized out>,
>     origin_lsn=0) at reorderbuffer.c:1397
> #1  0x00000000006bdd58 in DecodeCommit (ctx=0xdbe888, record=<value
> optimized out>) at decode.c:611
> #2  DecodeXactOp (ctx=0xdbe888, record=<value optimized out>) at decode.c:241
> #3  LogicalDecodingProcessRecord (ctx=0xdbe888, record=<value
> optimized out>) at decode.c:113
> #4  0x00000000006d0754 in XLogSendLogical () at walsender.c:2781
> #5  0x00000000006cf782 in WalSndLoop (send_data=0x6d0700
> <XLogSendLogical>) at walsender.c:2149
> #6  0x00000000006d1463 in StartLogicalReplication (cmd_string=<value
> optimized out>) at walsender.c:1102
> #7  exec_replication_command (cmd_string=<value optimized out>) at
> walsender.c:1539
> #8  0x00000000007182b9 in PostgresMain (argc=<value optimized out>,
> argv=<value optimized out>, dbname=0xd368a8 "foo", username=<value
> optimized out>) at postgres.c:4084
> #9  0x00000000006ad27d in BackendRun (argc=<value optimized out>,
> argv=<value optimized out>) at postmaster.c:4405
> #10 BackendStartup (argc=<value optimized out>, argv=<value optimized
> out>) at postmaster.c:4077
> #11 ServerLoop (argc=<value optimized out>, argv=<value optimized
> out>) at postmaster.c:1755
> #12 PostmasterMain (argc=<value optimized out>, argv=<value optimized
> out>) at postmaster.c:1363
> #13 0x000000000062e5b0 in main (argc=3, argv=0xd04540) at main.c:228
> (gdb) p change
> $1 = (ReorderBufferChange *) 0x0
> (gdb) p specinsert
> $2 = (ReorderBufferChange *) 0x0
> 
> If my math is correct the lsn 6211559254952 is 5A6/3DC86BA8. The transaction is:
> 
> rmgr: Btree       len (rec/tot):   3795/ 11731, tx:  144441221, lsn:
> 5A6/3DC80B58, prev 5A6/3DC80B28, desc: SPLIT_R level 0, firstright
> 139, blkref #0: rel 1663/355309/54931968 blk 176078, blkref #1: rel
> 1663/355309/54931968 blk 223615, blkref #2: rel 1663/355309/54931968
> blk 176079 FPW
> rmgr: Btree       len (rec/tot):     61/  4481, tx:  144441221, lsn:
> 5A6/3DC83948, prev 5A6/3DC80B58, desc: INSERT_UPPER off 39, blkref #0:
> rel 1663/355309/54931968 blk 176062 FPW, blkref #1: rel
> 1663/355309/54931968 blk 176078
> rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
> 5A6/3DC84AE8, prev 5A6/3DC83948, desc: INSERT_LEAF off 2, blkref #0:
> rel 1663/355309/57252673 blk 218754
> rmgr: Btree       len (rec/tot):     53/  7613, tx:  144441221, lsn:
> 5A6/3DC84B30, prev 5A6/3DC84AE8, desc: INSERT_LEAF off 129, blkref #0:
> rel 1663/355309/57252674 blk 23008 FPW
> rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
> 5A6/3DC86908, prev 5A6/3DC84B30, desc: INSERT_LEAF off 71, blkref #0:
> rel 1663/355309/57252998 blk 156099
> rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
> 5A6/3DC86948, prev 5A6/3DC86908, desc: INSERT_LEAF off 210, blkref #0:
> rel 1663/355309/57253000 blk 219630
> rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
> 5A6/3DC86990, prev 5A6/3DC86948, desc: HEAP_CONFIRM off 5, blkref #0:
> rel 1663/355309/382872 blk 5520503
> rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
> 5A6/3DC869C0, prev 5A6/3DC86990, desc: LOCK off 8: xid 144441221:
> flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42286702
> blk 0
> rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
> 5A6/3DC869F8, prev 5A6/3DC869C0, desc: LOCK off 1: xid 144441221:
> flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42323652
> blk 0
> rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
> 5A6/3DC86A30, prev 5A6/3DC869F8, desc: LOCK off 23: xid 144441221:
> flags 0 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/355309/382874 blk
> 4688787
> rmgr: Heap        len (rec/tot):    211/   211, tx:  144441221, lsn:
> 5A6/3DC86A68, prev 5A6/3DC86A30, desc: HOT_UPDATE off 23 xmax
> 144441221 ; new off 24 xmax 144441221, blkref #0: rel
> 1663/355309/382874 blk 4688787
> rmgr: Heap        len (rec/tot):     98/    98, tx:  144441221, lsn:
> 5A6/3DC86B40, prev 5A6/3DC86A68, desc: HOT_UPDATE off 32 xmax
> 144441221 ; new off 34 xmax 0, blkref #0: rel 1663/355309/39370447 blk
> 6284
> rmgr: Transaction len (rec/tot):     46/    46, tx:  144441221, lsn:
> 5A6/3DC86BA8, prev 5A6/3DC86B40, desc: COMMIT 2018-05-21
> 10:26:05.830168 -03
> 
> which translates into something like:
> 
> BEGIN
> INSERT INTO table_a ON CONFLICT
> UPDATE table_b
> UPDATE table_c
> COMMIT
> 
> I don't have a test case yet. This is my next step after this report.
> However, it seems to be related to INSERT ON CONFLICT decoding. Ideas?

CC: Peter?

Greetings,

Andres Freund


Re: crash while decoding INSERT ON CONFLICT

From
Peter Geoghegan
Date:
On Mon, May 21, 2018 at 8:52 AM, Euler Taveira <euler@timbira.com.br> wrote:
> If my math is correct the lsn 6211559254952 is 5A6/3DC86BA8. The transaction is:

Are you sure you're not missing some earlier records for this xact? I
see a HEAP_CONFIRM record without any preceding HEAP_INSERT. This
doesn't make any sense, though I half-suspect that that's the actual
problem: we have a HEAP_CONFIRM without anything to confirm. (I
actually doubt that you omitted WAL records, but I must still ask if
it's a simple mistake, just to be sure.)

If you really do have all the records for the xact whose commit record
is at 5A6/3DC86BA8, then the immediate problem is obvious: control
flow within ReorderBufferCommit() expects to have found a specinsert
that corresponds to a HEAP_CONFIRM or
REORDER_BUFFER_CHANGE_INTERNAL_SPEC_CONFIRM, but that assumption has
somehow been violated -- specInsert is still NULL, leading to a
segfault. I have no idea why that should be right now; that's just
what it looks like on the face of it.

-- 
Peter Geoghegan


Re: crash while decoding INSERT ON CONFLICT

From
Euler Taveira
Date:
2018-05-21 14:59 GMT-03:00 Peter Geoghegan <pg@bowt.ie>:
> On Mon, May 21, 2018 at 8:52 AM, Euler Taveira <euler@timbira.com.br> wrote:
>> If my math is correct the lsn 6211559254952 is 5A6/3DC86BA8. The transaction is:
>
> Are you sure you're not missing some earlier records for this xact? I
> see a HEAP_CONFIRM record without any preceding HEAP_INSERT. This
> doesn't make any sense, though I half-suspect that that's the actual
> problem: we have a HEAP_CONFIRM without anything to confirm. (I
> actually doubt that you omitted WAL records, but I must still ask if
> it's a simple mistake, just to be sure.)
>
Yep. I forgot to send the first part of the transaction because I
searched by lsn and then forgot to search by that transaction. Here is
the complete output:

rmgr: Heap        len (rec/tot):    335/   335, tx:  144441221, lsn:
5A6/3DC1A478, prev 5A6/3DC1A448, desc: INSERT off 22, blkref #0: rel
1663/355309/382889 blk 1786937
rmgr: Btree       len (rec/tot):     53/  7353, tx:  144441221, lsn:
5A6/3DC1A5C8, prev 5A6/3DC1A478, desc: INSERT_LEAF off 232, blkref #0:
rel 1663/355309/46488102 blk 138223 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC1C2A0, prev 5A6/3DC1A5C8, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48166457 blk 1
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC1C2E0, prev 5A6/3DC1C2A0, desc: INSERT_LEAF off 157, blkref #0:
rel 1663/355309/48166458 blk 62259
rmgr: Btree       len (rec/tot):     53/  4513, tx:  144441221, lsn:
5A6/3DC1C320, prev 5A6/3DC1C2E0, desc: INSERT_LEAF off 15, blkref #0:
rel 1663/355309/48166459 blk 362995 FPW
rmgr: Btree       len (rec/tot):     53/  7893, tx:  144441221, lsn:
5A6/3DC1D4C8, prev 5A6/3DC1C320, desc: INSERT_LEAF off 105, blkref #0:
rel 1663/355309/48166460 blk 37962 FPW
rmgr: Btree       len (rec/tot):     53/  7913, tx:  144441221, lsn:
5A6/3DC1F3B8, prev 5A6/3DC1D4C8, desc: INSERT_LEAF off 60, blkref #0:
rel 1663/355309/48166463 blk 43766 FPW
rmgr: Btree       len (rec/tot):     53/  5413, tx:  144441221, lsn:
5A6/3DC212C0, prev 5A6/3DC1F3B8, desc: INSERT_LEAF off 68, blkref #0:
rel 1663/355309/48171844 blk 6292 FPW
rmgr: Btree       len (rec/tot):     53/  7473, tx:  144441221, lsn:
5A6/3DC22800, prev 5A6/3DC212C0, desc: INSERT_LEAF off 192, blkref #0:
rel 1663/355309/48176501 blk 53409 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC24550, prev 5A6/3DC22800, desc: INSERT_LEAF off 38, blkref #0:
rel 1663/355309/48222806 blk 134616
rmgr: Btree       len (rec/tot):     53/  7661, tx:  144441221, lsn:
5A6/3DC24590, prev 5A6/3DC24550, desc: INSERT_LEAF off 123, blkref #0:
rel 1663/355309/48255609 blk 221282 FPW
rmgr: Btree       len (rec/tot):     53/  5217, tx:  144441221, lsn:
5A6/3DC26398, prev 5A6/3DC24590, desc: INSERT_LEAF off 94, blkref #0:
rel 1663/355309/48262197 blk 44534 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC27800, prev 5A6/3DC26398, desc: INSERT_LEAF off 88, blkref #0:
rel 1663/355309/48275659 blk 134614
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC27840, prev 5A6/3DC27800, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48286181 blk 1
rmgr: Btree       len (rec/tot):     53/  7457, tx:  144441221, lsn:
5A6/3DC27988, prev 5A6/3DC27958, desc: INSERT_LEAF off 98, blkref #0:
rel 1663/355309/48292403 blk 44553 FPW
rmgr: Btree       len (rec/tot):     53/  7457, tx:  144441221, lsn:
5A6/3DC29B90, prev 5A6/3DC29B60, desc: INSERT_LEAF off 33, blkref #0:
rel 1663/355309/48319209 blk 42505 FPW
rmgr: Btree       len (rec/tot):     53/  7457, tx:  144441221, lsn:
5A6/3DC2B8D0, prev 5A6/3DC29B90, desc: INSERT_LEAF off 99, blkref #0:
rel 1663/355309/48326655 blk 44553 FPW
rmgr: Btree       len (rec/tot):     53/  7541, tx:  144441221, lsn:
5A6/3DC2D610, prev 5A6/3DC2B8D0, desc: INSERT_LEAF off 71, blkref #0:
rel 1663/355309/48364917 blk 134855 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC2F3D8, prev 5A6/3DC2F3A0, desc: INSERT_LEAF off 128, blkref #0:
rel 1663/355309/48366893 blk 8939
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC2F418, prev 5A6/3DC2F3D8, desc: INSERT_LEAF off 105, blkref #0:
rel 1663/355309/48375917 blk 9710
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC2F458, prev 5A6/3DC2F418, desc: INSERT_LEAF off 151, blkref #0:
rel 1663/355309/48392267 blk 9009
rmgr: Btree       len (rec/tot):     53/  4653, tx:  144441221, lsn:
5A6/3DC2F498, prev 5A6/3DC2F458, desc: INSERT_LEAF off 21, blkref #0:
rel 1663/355309/48393908 blk 148070 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC306E0, prev 5A6/3DC2F498, desc: INSERT_LEAF off 3, blkref #0:
rel 1663/355309/48398929 blk 153013
rmgr: Btree       len (rec/tot):     53/  5613, tx:  144441221, lsn:
5A6/3DC30720, prev 5A6/3DC306E0, desc: INSERT_LEAF off 140, blkref #0:
rel 1663/355309/48422100 blk 141177 FPW
rmgr: Btree       len (rec/tot):     53/  7453, tx:  144441221, lsn:
5A6/3DC31D10, prev 5A6/3DC30720, desc: INSERT_LEAF off 308, blkref #0:
rel 1663/355309/48458258 blk 94582 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC33A48, prev 5A6/3DC31D10, desc: INSERT_LEAF off 7, blkref #0:
rel 1663/355309/48463333 blk 145616
rmgr: Btree       len (rec/tot):     53/  7633, tx:  144441221, lsn:
5A6/3DC33A88, prev 5A6/3DC33A48, desc: INSERT_LEAF off 180, blkref #0:
rel 1663/355309/48687881 blk 33026 FPW
rmgr: Btree       len (rec/tot):     53/  7549, tx:  144441221, lsn:
5A6/3DC3F120, prev 5A6/3DC3E100, desc: INSERT_LEAF off 93, blkref #0:
rel 1663/355309/72204267 blk 26594 FPW
rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
5A6/3DC40EB8, prev 5A6/3DC3F120, desc: HEAP_CONFIRM off 22, blkref #0:
rel 1663/355309/382889 blk 1786937
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC40EE8, prev 5A6/3DC40EB8, desc: LOCK off 5: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/41910223
blk 230
rmgr: Heap        len (rec/tot):     59/  7971, tx:  144441221, lsn:
5A6/3DC40F20, prev 5A6/3DC40EE8, desc: LOCK off 34: xid 144441221:
flags 1 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/5094899 blk
44069 FPW
rmgr: Heap        len (rec/tot):     59/  7619, tx:  144441221, lsn:
5A6/3DC42E60, prev 5A6/3DC40F20, desc: LOCK off 19: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/5094899 blk
79637 FPW
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44C40, prev 5A6/3DC42E60, desc: LOCK off 72: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42211759
blk 1
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44C78, prev 5A6/3DC44C40, desc: LOCK off 91: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42211925
blk 5
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44CB0, prev 5A6/3DC44C78, desc: LOCK off 80: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42211925
blk 13
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44CE8, prev 5A6/3DC44CB0, desc: LOCK off 5: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42240984
blk 13
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44D20, prev 5A6/3DC44CE8, desc: LOCK off 13: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42272788
blk 0
rmgr: MultiXact   len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44D58, prev 5A6/3DC44D20, desc: CREATE_ID 8141708 offset
26509253 nmembers 2: 144439567 (keysh) 144441221 (keysh)
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44D90, prev 5A6/3DC44D58, desc: LOCK off 25: xid 8141708: flags
0 IS_MULTI LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42290062
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44DC8, prev 5A6/3DC44D90, desc: LOCK off 20: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42290296
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44E00, prev 5A6/3DC44DC8, desc: LOCK off 1: xid 8141708: flags
0 IS_MULTI LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42324282
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC44E38, prev 5A6/3DC44E00, desc: LOCK off 1: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42330935
blk 0
rmgr: Heap        len (rec/tot):    125/   125, tx:  144441221, lsn:
5A6/3DC44E70, prev 5A6/3DC44E38, desc: INSERT off 16, blkref #0: rel
1663/355309/382895 blk 1432184
rmgr: Btree       len (rec/tot):     53/  5261, tx:  144441221, lsn:
5A6/3DC44EF0, prev 5A6/3DC44E70, desc: INSERT_LEAF off 136, blkref #0:
rel 1663/355309/46466754 blk 602565 FPW
rmgr: Btree       len (rec/tot):     53/  6393, tx:  144441221, lsn:
5A6/3DC46398, prev 5A6/3DC44EF0, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48992112 blk 365102 FPW
rmgr: Btree       len (rec/tot):     53/  8033, tx:  144441221, lsn:
5A6/3DC47C98, prev 5A6/3DC46398, desc: INSERT_LEAF off 291, blkref #0:
rel 1663/355309/48992114 blk 367495 FPW
rmgr: Btree       len (rec/tot):   3558/  3558, tx:  144441221, lsn:
5A6/3DC49C18, prev 5A6/3DC47C98, desc: SPLIT_L level 0, firstright
192, blkref #0: rel 1663/355309/48992115 blk 1, blkref #1: rel
1663/355309/48992115 blk 365776, blkref #2: rel 1663/355309/48992115
blk 365773
rmgr: Btree       len (rec/tot):     61/  7393, tx:  144441221, lsn:
5A6/3DC4AA18, prev 5A6/3DC49C18, desc: INSERT_UPPER off 3, blkref #0:
rel 1663/355309/48992115 blk 3 FPW, blkref #1: rel
1663/355309/48992115 blk 1
rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
5A6/3DC4C718, prev 5A6/3DC4AA18, desc: HEAP_CONFIRM off 16, blkref #0:
rel 1663/355309/382895 blk 1432184
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC4C748, prev 5A6/3DC4C718, desc: LOCK off 14: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42246107
blk 2
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC4C780, prev 5A6/3DC4C748, desc: LOCK off 1: xid 8141708: flags
0 IS_MULTI LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42329427
blk 0
rmgr: Heap2       len (rec/tot):     70/    70, tx:  144441221, lsn:
5A6/3DC4C7B8, prev 5A6/3DC4C780, desc: CLEAN remxid 144435657, blkref
#0: rel 1663/355309/382889 blk 1786937
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC4C800, prev 5A6/3DC4C7B8, desc: LOCK off 22: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/382889 blk
1786937
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC4C838, prev 5A6/3DC4C800, desc: LOCK off 22: xid 144441221:
flags 0 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/355309/382889 blk
1786937
rmgr: Heap        len (rec/tot):    346/   346, tx:  144441221, lsn:
5A6/3DC4C870, prev 5A6/3DC4C838, desc: UPDATE off 22 xmax 144441221 ;
new off 23 xmax 144441221, blkref #0: rel 1663/355309/382889 blk
1786937
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4C9D0, prev 5A6/3DC4C870, desc: INSERT_LEAF off 232, blkref #0:
rel 1663/355309/46488102 blk 138223
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CA10, prev 5A6/3DC4C9D0, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48166457 blk 1
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CA50, prev 5A6/3DC4CA10, desc: INSERT_LEAF off 157, blkref #0:
rel 1663/355309/48166458 blk 62259
rmgr: Btree       len (rec/tot):    112/   112, tx:  144441221, lsn:
5A6/3DC4CA90, prev 5A6/3DC4CA50, desc: INSERT_LEAF off 15, blkref #0:
rel 1663/355309/48166459 blk 362995
rmgr: Btree       len (rec/tot):    104/   104, tx:  144441221, lsn:
5A6/3DC4CB00, prev 5A6/3DC4CA90, desc: INSERT_LEAF off 105, blkref #0:
rel 1663/355309/48166460 blk 37962
rmgr: Btree       len (rec/tot):    112/   112, tx:  144441221, lsn:
5A6/3DC4CB68, prev 5A6/3DC4CB00, desc: INSERT_LEAF off 60, blkref #0:
rel 1663/355309/48166463 blk 43766
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CBD8, prev 5A6/3DC4CB68, desc: INSERT_LEAF off 68, blkref #0:
rel 1663/355309/48171844 blk 6292
rmgr: Btree       len (rec/tot):     80/    80, tx:  144441221, lsn:
5A6/3DC4CC18, prev 5A6/3DC4CBD8, desc: INSERT_LEAF off 192, blkref #0:
rel 1663/355309/48176501 blk 53409
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CC68, prev 5A6/3DC4CC18, desc: INSERT_LEAF off 38, blkref #0:
rel 1663/355309/48222806 blk 134616
rmgr: Btree       len (rec/tot):     80/    80, tx:  144441221, lsn:
5A6/3DC4CCA8, prev 5A6/3DC4CC68, desc: INSERT_LEAF off 123, blkref #0:
rel 1663/355309/48255609 blk 221282
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4CCF8, prev 5A6/3DC4CCA8, desc: INSERT_LEAF off 94, blkref #0:
rel 1663/355309/48262197 blk 44534
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CD40, prev 5A6/3DC4CCF8, desc: INSERT_LEAF off 88, blkref #0:
rel 1663/355309/48275659 blk 134614
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CD80, prev 5A6/3DC4CD40, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48286181 blk 1
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4CDC0, prev 5A6/3DC4CD80, desc: INSERT_LEAF off 98, blkref #0:
rel 1663/355309/48292403 blk 44553
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4CE08, prev 5A6/3DC4CDC0, desc: INSERT_LEAF off 33, blkref #0:
rel 1663/355309/48319209 blk 42505
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4CE50, prev 5A6/3DC4CE08, desc: INSERT_LEAF off 99, blkref #0:
rel 1663/355309/48326655 blk 44553
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4CE98, prev 5A6/3DC4CE50, desc: INSERT_LEAF off 71, blkref #0:
rel 1663/355309/48364917 blk 134855
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CEE0, prev 5A6/3DC4CE98, desc: INSERT_LEAF off 128, blkref #0:
rel 1663/355309/48366893 blk 8939
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CF20, prev 5A6/3DC4CEE0, desc: INSERT_LEAF off 105, blkref #0:
rel 1663/355309/48375917 blk 9710
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CF60, prev 5A6/3DC4CF20, desc: INSERT_LEAF off 151, blkref #0:
rel 1663/355309/48392267 blk 9009
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CFA0, prev 5A6/3DC4CF60, desc: INSERT_LEAF off 21, blkref #0:
rel 1663/355309/48393908 blk 148070
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4CFE0, prev 5A6/3DC4CFA0, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/48398929 blk 146957
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4D020, prev 5A6/3DC4CFE0, desc: INSERT_LEAF off 140, blkref #0:
rel 1663/355309/48422100 blk 141177
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4D060, prev 5A6/3DC4D020, desc: INSERT_LEAF off 308, blkref #0:
rel 1663/355309/48458258 blk 94582
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4D0A0, prev 5A6/3DC4D060, desc: INSERT_LEAF off 7, blkref #0:
rel 1663/355309/48463333 blk 145616
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC4D0E0, prev 5A6/3DC4D0A0, desc: INSERT_LEAF off 180, blkref #0:
rel 1663/355309/48687881 blk 33026
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC4D120, prev 5A6/3DC4D0E0, desc: INSERT_LEAF off 93, blkref #0:
rel 1663/355309/72204267 blk 26594
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC4D4D8, prev 5A6/3DC4D498, desc: LOCK off 16: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42324281
blk 0
rmgr: Heap        len (rec/tot):    112/   112, tx:  144441221, lsn:
5A6/3DC51F20, prev 5A6/3DC51EE0, desc: INSERT off 39, blkref #0: rel
1663/355309/25332667 blk 53769
rmgr: Btree       len (rec/tot):     53/  4433, tx:  144441221, lsn:
5A6/3DC51FD0, prev 5A6/3DC51F90, desc: INSERT_LEAF off 146, blkref #0:
rel 1663/355309/45934917 blk 3486 FPW
rmgr: Btree       len (rec/tot):     53/  8129, tx:  144441221, lsn:
5A6/3DC54CC8, prev 5A6/3DC54C98, desc: INSERT_LEAF off 244, blkref #0:
rel 1663/355309/46159842 blk 12634 FPW
rmgr: Btree       len (rec/tot):     53/  8213, tx:  144441221, lsn:
5A6/3DC57CB8, prev 5A6/3DC57C88, desc: INSERT_LEAF off 280, blkref #0:
rel 1663/355309/46160285 blk 3952 FPW
rmgr: Btree       len (rec/tot):     53/  5641, tx:  144441221, lsn:
5A6/3DC59CE8, prev 5A6/3DC57CB8, desc: INSERT_LEAF off 96, blkref #0:
rel 1663/355309/46160286 blk 16005 FPW
rmgr: Btree       len (rec/tot):     53/  7509, tx:  144441221, lsn:
5A6/3DC62158, prev 5A6/3DC62120, desc: INSERT_LEAF off 126, blkref #0:
rel 1663/355309/46160288 blk 4404 FPW
rmgr: Btree       len (rec/tot):     53/  7673, tx:  144441221, lsn:
5A6/3DC78A80, prev 5A6/3DC78A40, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/46160677 blk 5668 FPW
rmgr: Btree       len (rec/tot):     53/  7453, tx:  144441221, lsn:
5A6/3DC7A898, prev 5A6/3DC78A80, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/46160774 blk 3441 FPW
rmgr: Btree       len (rec/tot):     53/  4593, tx:  144441221, lsn:
5A6/3DC7C5D0, prev 5A6/3DC7A898, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/46162416 blk 11910 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC7D7C8, prev 5A6/3DC7C5D0, desc: INSERT_LEAF off 164, blkref #0:
rel 1663/355309/46164900 blk 482
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC7D908, prev 5A6/3DC7D8D8, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/46164920 blk 11916
rmgr: Btree       len (rec/tot):     53/  7633, tx:  144441221, lsn:
5A6/3DC7D948, prev 5A6/3DC7D908, desc: INSERT_LEAF off 203, blkref #0:
rel 1663/355309/46168215 blk 4008 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC7F738, prev 5A6/3DC7D948, desc: INSERT_LEAF off 13, blkref #0:
rel 1663/355309/46168862 blk 11710
rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
5A6/3DC7F778, prev 5A6/3DC7F738, desc: HEAP_CONFIRM off 39, blkref #0:
rel 1663/355309/25332667 blk 53769
rmgr: Heap        len (rec/tot):    610/   610, tx:  144441221, lsn:
5A6/3DC807C0, prev 5A6/3DC80780, desc: INSERT off 5, blkref #0: rel
1663/355309/382872 blk 5520503
rmgr: Btree       len (rec/tot):   3795/ 11731, tx:  144441221, lsn:
5A6/3DC80B58, prev 5A6/3DC80B28, desc: SPLIT_R level 0, firstright
139, blkref #0: rel 1663/355309/54931968 blk 176078, blkref #1: rel
1663/355309/54931968 blk 223615, blkref #2: rel 1663/355309/54931968
blk 176079 FPW
rmgr: Btree       len (rec/tot):     61/  4481, tx:  144441221, lsn:
5A6/3DC83948, prev 5A6/3DC80B58, desc: INSERT_UPPER off 39, blkref #0:
rel 1663/355309/54931968 blk 176062 FPW, blkref #1: rel
1663/355309/54931968 blk 176078
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC84AE8, prev 5A6/3DC83948, desc: INSERT_LEAF off 2, blkref #0:
rel 1663/355309/57252673 blk 218754
rmgr: Btree       len (rec/tot):     53/  7613, tx:  144441221, lsn:
5A6/3DC84B30, prev 5A6/3DC84AE8, desc: INSERT_LEAF off 129, blkref #0:
rel 1663/355309/57252674 blk 23008 FPW
rmgr: Btree       len (rec/tot):     64/    64, tx:  144441221, lsn:
5A6/3DC86908, prev 5A6/3DC84B30, desc: INSERT_LEAF off 71, blkref #0:
rel 1663/355309/57252998 blk 156099
rmgr: Btree       len (rec/tot):     72/    72, tx:  144441221, lsn:
5A6/3DC86948, prev 5A6/3DC86908, desc: INSERT_LEAF off 210, blkref #0:
rel 1663/355309/57253000 blk 219630
rmgr: Heap        len (rec/tot):     48/    48, tx:  144441221, lsn:
5A6/3DC86990, prev 5A6/3DC86948, desc: HEAP_CONFIRM off 5, blkref #0:
rel 1663/355309/382872 blk 5520503
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC869C0, prev 5A6/3DC86990, desc: LOCK off 8: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42286702
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC869F8, prev 5A6/3DC869C0, desc: LOCK off 1: xid 144441221:
flags 0 LOCK_ONLY KEYSHR_LOCK , blkref #0: rel 1663/355309/42323652
blk 0
rmgr: Heap        len (rec/tot):     54/    54, tx:  144441221, lsn:
5A6/3DC86A30, prev 5A6/3DC869F8, desc: LOCK off 23: xid 144441221:
flags 0 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/355309/382874 blk
4688787
rmgr: Heap        len (rec/tot):    211/   211, tx:  144441221, lsn:
5A6/3DC86A68, prev 5A6/3DC86A30, desc: HOT_UPDATE off 23 xmax
144441221 ; new off 24 xmax 144441221, blkref #0: rel
1663/355309/382874 blk 4688787
rmgr: Heap        len (rec/tot):     98/    98, tx:  144441221, lsn:
5A6/3DC86B40, prev 5A6/3DC86A68, desc: HOT_UPDATE off 32 xmax
144441221 ; new off 34 xmax 0, blkref #0: rel 1663/355309/39370447 blk
6284
rmgr: Transaction len (rec/tot):     46/    46, tx:  144441221, lsn:
5A6/3DC86BA8, prev 5A6/3DC86B40, desc: COMMIT 2018-05-21
10:26:05.830168 -03


-- 
   Euler Taveira                                   Timbira -
http://www.timbira.com.br/
   PostgreSQL: Consultoria, Desenvolvimento, Suporte 24x7 e Treinamento


Re: crash while decoding INSERT ON CONFLICT

From
Peter Geoghegan
Date:
On Mon, May 21, 2018 at 11:04 AM, Euler Taveira <euler@timbira.com.br> wrote:
> Yep. I forgot to send the first part of the transaction because I
> searched by lsn and then forgot to search by that transaction. Here is
> the complete output:

Can you give me a bit more info about the definition of the tables
that you're using ON CONFLICT with here? There appear to be a total of
4 -- 1 for each distinct speculative insertion in the xact. Do they
have any triggers, for example? (As you probably know, you can use
pg_filenode_relation() to figure out which relations these are, to get
those details.)

-- 
Peter Geoghegan


Re: crash while decoding INSERT ON CONFLICT

From
Peter Geoghegan
Date:
On Mon, May 21, 2018 at 8:52 AM, Euler Taveira <euler@timbira.com.br> wrote:
> I got the following backtrace in a logical replication setup using 10.3.
>
> Program terminated with signal 11, Segmentation fault.
> #0  ReorderBufferCommit (rb=0xde2a08, xid=<value optimized out>,
> commit_lsn=6211559254952, end_lsn=<value optimized out>,
> commit_time=<value optimized out>, origin_id=<value optimized out>,
>     origin_lsn=0) at reorderbuffer.c:1397
> 1397                                            change->action =
> REORDER_BUFFER_CHANGE_INSERT;
> Missing separate debuginfos, use: debuginfo-install
> glibc-2.12-1.209.el6_9.2.x86_64 libxml2-2.7.6-21.el6_8.1.x86_64
> zlib-1.2.3-29.el6.x86_64
> (gdb) bt

Can I get this as a "bt full", in case any of the local variables turn
out to be interesting?

Thanks
-- 
Peter Geoghegan


Re: crash while decoding INSERT ON CONFLICT

From
Euler Taveira
Date:
2018-05-21 17:15 GMT-03:00 Peter Geoghegan <pg@bowt.ie>:
> Can I get this as a "bt full", in case any of the local variables turn
> out to be interesting?
>
(gdb) bt full
#0  ReorderBufferCommit (rb=0xde14c8, xid=<value optimized out>,
commit_lsn=6211559254952, end_lsn=<value optimized out>,
commit_time=<value optimized out>, origin_id=<value optimized out>,
    origin_lsn=0) at reorderbuffer.c:1397
        relation = 0x0
        reloid = <value optimized out>
        change = 0x0
        specinsert = 0x0
        save_exception_stack = 0x7fff367fd9e0
        save_context_stack = 0x0
        local_sigjmp_buf = {{__jmpbuf = {6211559255000,
4463254845150949641, 0, 6211559255000, 144441221, 0,
-2494219915992272627, 2494057498805104909}, __mask_was_saved = 0,
__saved_mask = {
              __val = {8522252, 13894872, 4096, 209054130552,
209054130464, 4, 0, 140734107735660, 140734107735679, 0, 64, 2608,
8526491, 2608, 8522252, 0}}}}
        txn = 0xdf7fd8
        snapshot_now = 0xd42718
        command_id = 0
        using_subtxn = 0 '\000'
        iterstate = 0xde15d8
        __func__ = "ReorderBufferCommit"
#1  0x00000000006bdd58 in DecodeCommit (ctx=0xdbe888, record=<value
optimized out>) at decode.c:611
        origin_lsn = 0
        commit_time = 580224365830168
        origin_id = 0
        i = <value optimized out>
#2  DecodeXactOp (ctx=0xdbe888, record=<value optimized out>) at decode.c:241
        xlrec = <value optimized out>
        parsed = {xact_time = 580224365830168, xinfo = 1, dbId =
355309, tsId = 1663, nsubxacts = 0, subxacts = 0x0, nrels = 0, xnodes
= 0x0, nmsgs = 0, msgs = 0x0, twophase_xid = 0,
          origin_lsn = 0, origin_timestamp = 0}
        xid = 144441221
        builder = <value optimized out>
        reorder = <value optimized out>
        info = <value optimized out>
        r = <value optimized out>
#3  LogicalDecodingProcessRecord (ctx=0xdbe888, record=<value
optimized out>) at decode.c:113
        __func__ = "LogicalDecodingProcessRecord"
#4  0x00000000006d0754 in XLogSendLogical () at walsender.c:2781
        record = <value optimized out>
        errm = 0x0
        __func__ = "XLogSendLogical"
#5  0x00000000006cf782 in WalSndLoop (send_data=0x6d0700
<XLogSendLogical>) at walsender.c:2149
        now = <value optimized out>
        __func__ = "WalSndLoop"
#6  0x00000000006d1463 in StartLogicalReplication (cmd_string=<value
optimized out>) at walsender.c:1102
        buf = {data = 0x0, len = 3, maxlen = 1024, cursor = 87}
#7  exec_replication_command (cmd_string=<value optimized out>) at
walsender.c:1539
        cmd = 0xd24928
        parse_rc = <value optimized out>
        cmd_node = 0xd24928
        cmd_context = 0xd56f48
        old_context = 0xd04828
        __func__ = "exec_replication_command"
#8  0x00000000007182b9 in PostgresMain (argc=<value optimized out>,
argv=<value optimized out>, dbname=0xd368a8 "foo", username=<value
optimized out>) at postgres.c:4084
        query_string = 0xdc37c8 "START_REPLICATION SLOT
\"sub_xxxxxx_xxxxxx_01_011\" LOGICAL 0/0 (proto_version '1',
publication_names '\"pub_xxxxxxxxxx_xxxxxx\"')"
        firstchar = <value optimized out>
        input_message = {data = 0xdc37c8 "START_REPLICATION SLOT
\"sub_xxxxxx_xxxxxx_01_011\" LOGICAL 0/0 (proto_version '1',
publication_names '\"pub_xxxxxxxxxx_xxxxxx\"')", len = 127,
          maxlen = 1024, cursor = 127}
        local_sigjmp_buf = {{__jmpbuf = {140734107736816,
2494058286424355085, 13791920, 1526910016, 0, 1526907023,
-2494219915887415027, 2494057610916884749}, __mask_was_saved = 1,
            __saved_mask = {__val = {0, 0, 0, 0, 0, 0, 0,
209050462168, 140345725128704, 0, 4294967295, 0, 1, 13116160, 0, 0}}}}
        send_ready_for_query = 0 '\000'
        disable_idle_in_transaction_timeout = 0 '\000'
        __func__ = "PostgresMain"
#9  0x00000000006ad27d in BackendRun (argc=<value optimized out>,
argv=<value optimized out>) at postmaster.c:4405
        ac = 1
        usecs = 102525
        i = 1
        av = 0xd47ff0
        maxac = <value optimized out>
#10 BackendStartup (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:4077
        bn = <value optimized out>
        pid = 0
#11 ServerLoop (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:1755
        rmask = {fds_bits = {8, 0 <repeats 15 times>}}
        selres = <value optimized out>
        now = <value optimized out>
        readmask = {fds_bits = {56, 0 <repeats 15
times>}}zlib-1.2.3-29.el6.x86_64
>> (gdb) bt
>
> Can I get this as a "bt full", in case any of the local variables turn
> out to be interesting?
>
(gdb) bt full
#0  ReorderBufferCommit (rb=0xde14c8, xid=<value optimized out>,
commit_lsn=6211559254952, end_lsn=<value optimized out>,
commit_time=<value optimized out>, origin_id=<value optimized out>,
    origin_lsn=0) at reorderbuffer.c:1397
        relation = 0x0
        reloid = <value optimized out>
        change = 0x0
        specinsert = 0x0
        save_exception_stack = 0x7fff367fd9e0
        save_context_stack = 0x0
        local_sigjmp_buf = {{__jmpbuf = {6211559255000,
4463254845150949641, 0, 6211559255000, 144441221, 0,
-2494219915992272627, 2494057498805104909}, __mask_was_saved = 0,
__saved_mask = {
              __val = {8522252, 13894872, 4096, 209054130552,
209054130464, 4, 0, 140734107735660, 140734107735679, 0, 64, 2608,
8526491, 2608, 8522252, 0}}}}
        txn = 0xdf7fd8
        snapshot_now = 0xd42718
        command_id = 0
        using_subtxn = 0 '\000'
        iterstate = 0xde15d8
        __func__ = "ReorderBufferCommit"
#1  0x00000000006bdd58 in DecodeCommit (ctx=0xdbe888, record=<value
optimized out>) at decode.c:611
        origin_lsn = 0
        commit_time = 580224365830168
        origin_id = 0
        i = <value optimized out>
#2  DecodeXactOp (ctx=0xdbe888, record=<value optimized out>) at decode.c:241
        xlrec = <value optimized out>
        parsed = {xact_time = 580224365830168, xinfo = 1, dbId =
355309, tsId = 1663, nsubxacts = 0, subxacts = 0x0, nrels = 0, xnodes
= 0x0, nmsgs = 0, msgs = 0x0, twophase_xid = 0,
          origin_lsn = 0, origin_timestamp = 0}
        xid = 144441221
        builder = <value optimized out>
        reorder = <value optimized out>
        info = <value optimized out>
        r = <value optimized out>
#3  LogicalDecodingProcessRecord (ctx=0xdbe888, record=<value
optimized out>) at decode.c:113
        __func__ = "LogicalDecodingProcessRecord"
#4  0x00000000006d0754 in XLogSendLogical () at walsender.c:2781
        record = <value optimized out>
        errm = 0x0
        __func__ = "XLogSendLogical"
#5  0x00000000006cf782 in WalSndLoop (send_data=0x6d0700
<XLogSendLogical>) at walsender.c:2149
        now = <value optimized out>
        __func__ = "WalSndLoop"
#6  0x00000000006d1463 in StartLogicalReplication (cmd_string=<value
optimized out>) at walsender.c:1102
        buf = {data = 0x0, len = 3, maxlen = 1024, cursor = 87}
#7  exec_replication_command (cmd_string=<value optimized out>) at
walsender.c:1539
        cmd = 0xd24928
        parse_rc = <value optimized out>
        cmd_node = 0xd24928
        cmd_context = 0xd56f48
        old_context = 0xd04828
        __func__ = "exec_replication_command"
#8  0x00000000007182b9 in PostgresMain (argc=<value optimized out>,
argv=<value optimized out>, dbname=0xd368a8 "foo", username=<value
optimized out>) at postgres.c:4084
        query_string = 0xdc37c8 "START_REPLICATION SLOT
\"sub_xxxxxx_xxxxxx_01_011\" LOGICAL 0/0 (proto_version '1',
publication_names '\"pub_xxxxxxxxxx_xxxxxx\"')"
        firstchar = <value optimized out>
        input_message = {data = 0xdc37c8 "START_REPLICATION SLOT
\"sub_xxxxxx_xxxxxx_01_011\" LOGICAL 0/0 (proto_version '1',
publication_names '\"pub_xxxxxxxxxx_xxxxxx\"')", len = 127,
          maxlen = 1024, cursor = 127}
        local_sigjmp_buf = {{__jmpbuf = {140734107736816,
2494058286424355085, 13791920, 1526910016, 0, 1526907023,
-2494219915887415027, 2494057610916884749}, __mask_was_saved = 1,
            __saved_mask = {__val = {0, 0, 0, 0, 0, 0, 0,
209050462168, 140345725128704, 0, 4294967295, 0, 1, 13116160, 0, 0}}}}
        send_ready_for_query = 0 '\000'
        disable_idle_in_transaction_timeout = 0 '\000'
        __func__ = "PostgresMain"
#9  0x00000000006ad27d in BackendRun (argc=<value optimized out>,
argv=<value optimized out>) at postmaster.c:4405
        ac = 1
        usecs = 102525
        i = 1
        av = 0xd47ff0
        maxac = <value optimized out>
#10 BackendStartup (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:4077
        bn = <value optimized out>
        pid = 0
#11 ServerLoop (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:1755
        rmask = {fds_bits = {8, 0 <repeats 15 times>}}
        selres = <value optimized out>
        now = <value optimized out>
        readmask = {fds_bits = {56, 0 <repeats 15 times>}}
        nSockets = 6
        last_lockfile_recheck_time = 1526910016
        last_touch_time = 1526907023
#12 PostmasterMain (argc=<value optimized out>, argv=<value optimized
out>) at postmaster.c:1363
        opt = <value optimized out>
        status = <value optimized out>
        userDoption = <value optimized out>
        listen_addr_saved = <value optimized out>
        i = <value optimized out>
        output_config_variable = <value optimized out>
        __func__ = "PostmasterMain"
#13 0x000000000062e5b0 in main (argc=3, argv=0xd04540) at main.c:228
No locals.


-- 
   Euler Taveira                                   Timbira -
http://www.timbira.com.br/
   PostgreSQL: Consultoria, Desenvolvimento, Suporte 24x7 e Treinamento


Re: crash while decoding INSERT ON CONFLICT

From
Peter Geoghegan
Date:
On Mon, May 21, 2018 at 1:31 PM, Euler Taveira <euler@timbira.com.br> wrote:
> (gdb) bt full

Have you managed to see the crash more than once in your environment?
I wonder if the problem is somehow related to spilling to a reorder
buffer temp/spool file.

I must admit that I don't really understand the interactions between
this code, within ReorderBufferCommit():

                case REORDER_BUFFER_CHANGE_INTERNAL_SPEC_INSERT:

                    /*
                     * Speculative insertions are dealt with by delaying the
                     * processing of the insert until the confirmation record
                     * arrives. For that we simply unlink the record from the
                     * chain, so it does not get freed/reused while restoring
                     * spooled data from disk.
                     *
                     * ...
                     */

                   ...

                    /* and memorize the pending insertion */
                    dlist_delete(&change->node);
                    specinsert = change;
                    break;

...with the code for dealing with in-memory change records when
loading from disk, within ReorderBufferIterTXNNext():

    /* try to load changes from disk */
    if (entry->txn->nentries != entry->txn->nentries_mem)
    {
        /*
         * Ugly: restoring changes will reuse *Change records, thus delete the
         * current one from the per-tx list and only free in the next call.
         */
        dlist_delete(&change->node);
        dlist_push_tail(&state->old_change, &change->node);
        ...

Perhaps I've missed something obvious.

-- 
Peter Geoghegan


Re: crash while decoding INSERT ON CONFLICT

From
Euler Taveira
Date:
2018-05-21 22:37 GMT-03:00 Peter Geoghegan <pg@bowt.ie>:
> On Mon, May 21, 2018 at 1:31 PM, Euler Taveira <euler@timbira.com.br> wrote:
>> (gdb) bt full
>
> Have you managed to see the crash more than once in your environment?
> I wonder if the problem is somehow related to spilling to a reorder
> buffer temp/spool file.
>
When the system crashed, it restarted and crashed again, and again (in
the same transaction and with the same backtrace) until I blocked the
replication role in pg_hba.conf. I didn't check if there were files in
pg_replslot.


-- 
   Euler Taveira                                   Timbira -
http://www.timbira.com.br/
   PostgreSQL: Consultoria, Desenvolvimento, Suporte 24x7 e Treinamento