On 19.08.2016 19:06, Petr Jelinek wrote:

I don't think this will work correctly, there will be gap between when the new slot starts to decode and the drop of the old one as the new slot first needs to make snapshot.

Do I understand correctly that you are not using replication origins?

No, we are using replication origins to prevent recursive replication.
The gap is not a biggest problem because in multimaster we commit only those transaction which are acknowledged by all live nodes. So if some transaction falls in the gap... it is unlucky and will be aborted.


The problem is that for some reasons consistent point is not so
consistent and we get partly decoded transactions.
I.e. transaction body consists of two UPDATE but reorder_buffer extracts
only the one (last) update and sent this truncated transaction to
destination causing consistency violation at replica.  I started
investigation of logical decoding code and found several things which I
do not understand.

Never seen this happen. Do you have more details about what exactly is happening?


This is transaction at primary node:

root@knizhnik:/home/knizhnik/postgres_cluster/contrib/mmts# docker exec -ti node1 bash postgres@9a04a0c9f246:/pg$ pg_xlogdump data/pg_xlog/000000010000000000000001 | fgrep "tx: 6899" rmgr: Heap len (rec/tot): 7/ 53, tx: 6899, lsn: 0/019EFBD8, prev 0/019EFB80, desc: LOCK off 12: xid 6899 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/12407/16421 blk 60 rmgr: Heap len (rec/tot): 14/ 74, tx: 6899, lsn: 0/019EFC10, prev 0/019EFBD8, desc: HOT_UPDATE off 12 xmax 6899 ; new off 224 xmax 6899, blkref #0: rel 1663/12407/16421 blk 60 rmgr: Heap len (rec/tot): 7/ 53, tx: 6899, lsn: 0/019EFC60, prev 0/019EFC10, desc: LOCK off 153: xid 6899 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/12407/16421 blk 49 rmgr: Heap len (rec/tot): 14/ 82, tx: 6899, lsn: 0/019EFC98, prev 0/019EFC60, desc: UPDATE off 153 xmax 6899 ; new off 55 xmax 6899, blkref #0: rel 1663/12407/16421 blk 62, blkref #1: rel 1663/12407/16421 blk 49 rmgr: Btree len (rec/tot): 2/ 64, tx: 6899, lsn: 0/019EFCF0, prev 0/019EFC98, desc: INSERT_LEAF off 294, blkref #0: rel 1663/12407/16424 blk 23 rmgr: Transaction len (rec/tot): 236/ 265, tx: 6899, lsn: 0/019EFD30, prev 0/019EFCF0, desc: PREPARE pg_xlogdump: FATAL: error in WAL record at 0/1AC0E70: invalid record length at 0/1AC0EA8: wanted 24, got 0


This is the replicated transaction at other node (it is ont clear from the trace, but believe me, it is the same transaction):


root@knizhnik:/home/knizhnik/postgres_cluster/contrib/mmts# docker exec -ti node2 bash postgres@e5b16d82ce06:/pg$ pg_xlogdump data/pg_xlog/000000010000000000000001 | fgrep "tx: 6882" rmgr: Heap len (rec/tot): 14/ 74, tx: 6882, lsn: 0/019F3240, prev 0/019F31F0, desc: HOT_UPDATE off 113 xmax 6882 ; new off 219 xmax 0, blkref #0: rel 1663/12407/16421 blk 53 rmgr: Heap len (rec/tot): 14/ 82, tx: 6882, lsn: 0/019F5CB8, prev 0/019F5C60, desc: UPDATE off 163 xmax 6882 ; new off 4 xmax 0, blkref #0: rel 1663/12407/16421 blk 62, blkref #1: rel 1663/12407/16421 blk 51 rmgr: Btree len (rec/tot): 2/ 64, tx: 6882, lsn: 0/019F5D10, prev 0/019F5CB8, desc: INSERT_LEAF off 284, blkref #0: rel 1663/12407/16424 blk 23 rmgr: Transaction len (rec/tot): 248/ 274, tx: 6882, lsn: 0/019F61F8, prev 0/019F60E8, desc: PREPARE pg_xlogdump: FATAL: error in WAL record at 0/1AD3AD8: invalid record length at 0/1AD3B10: wanted 24, got 0


And "shorten" version of the same transaction at the third (recovered) node:

root@knizhnik:/home/knizhnik/postgres_cluster/contrib/mmts# docker exec -ti node3 bash postgres@b4066d4211bc:/pg$ pg_xlogdump data/pg_xlog/000000010000000000000001 | fgrep "tx: 6893" rmgr: Heap len (rec/tot): 7/ 53, tx: 6893, lsn: 0/01A29828, prev 0/01A297E0, desc: LOCK off 172: xid 6893 LOCK_ONLY EXCL_LOCK , blkref #0: rel 1663/12407/16421 blk 50 rmgr: Heap len (rec/tot): 14/ 82, tx: 6893, lsn: 0/01A29860, prev 0/01A29828, desc: UPDATE+INIT off 172 xmax 6893 ; new off 1 xmax 6893, blkref #0: rel 1663/12407/16421 blk 64, blkref #1: rel 1663/12407/16421 blk 50 rmgr: Btree len (rec/tot): 2/ 64, tx: 6893, lsn: 0/01A298B8, prev 0/01A29860, desc: INSERT_LEAF off 314, blkref #0: rel 1663/12407/16424 blk 23 rmgr: Transaction len (rec/tot): 236/ 265, tx: 6893, lsn: 0/01A298F8, prev 0/01A298B8, desc: PREPARE pg_xlogdump: FATAL: error in WAL record at 0/1ACBBF8: invalid record length at 0/1ACBC30: wanted 24, got 0

You can see one update instead of two.

Sorry, I have not saved trace with output of logical decoder. Bu t it really decodes just one update!
What I have done:

DROP_REPLICATION_SLOT "mtm_slot_1";
CREATE_REPLICATION_SLOT "mtm_slot_1" LOGICAL "multimaster";
START_REPLICATION SLOT "mtm_slot_1" LOGICAL 0/0 ("startup_params_format" '1', "max_proto_version" '1', "min_proto_version" '1', "forward_changesets" '1', "mtm_replication_mode" 'recovered');

I have also tried to calculate last origin LSN for this node and explicitly specify it in START_REPLICATION.
But it doesn't help: the same problem persists.





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



--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Reply via email to