[MDEV-10550] Parallel replication can't sync with master in InnoDB 5.7 (branch bb-10.2-jan) Created: 2016-08-12  Updated: 2021-01-08  Resolved: 2016-09-02

Status: Closed
Project: MariaDB Server
Component/s: Replication, Storage Engine - InnoDB
Affects Version/s: 10.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Blocks
is blocked by MDEV-10632 rpl.rpl_parallel fails in buildbot, F... Closed
PartOf
is part of MDEV-10024 Fix test failures on InnoDB 5.7 in Ma... Closed
Relates
relates to MDEV-15278 rpl.rpl_parallel_optimistic failed in... Closed

 Description   

This with InnoDB 5.7 with refactored lock0lock.cc in branch bb-10.2-jan commit 3f1b8c9474e351e50a6556675108864d5aac5528

Affected tests:

  • rpl.rpl_parallel
  • rpl_parallel_optimistic


 Comments   
Comment by Jan Lindström (Inactive) [ 2016-08-12 ]

Fixed actual mutexing problems, but still test failure:

 
rpl.rpl_parallel 'row,xtradb'            w8 [ fail ]
        Test ended at 2016-08-12 23:25:47
 
CURRENT_TEST: rpl.rpl_parallel
mysqltest: In included file "./include/sync_with_master_gtid.inc": 
included from /home/jan/mysql/10.2/mysql-test/suite/rpl/t/rpl_parallel.test at line 2174:
At line 48: Failed to sync with master
 
The result from queries just before the failure was:
< snip >
83	83
85	85
87	87
88	88
89	89
90	90
91	91
92	92
93	93
94	94
95	95
96	96
97	97
98	98
99	99
include/save_master_gtid.inc
connection server_2;
include/start_slave.inc
include/sync_with_master_gtid.inc
Timeout in master_gtid_wait('0-1-1114,1-1-10,2-1-8,3-1-1', 120), current slave GTID position is: 0-1-1076,1-1-10,2-1-8,3-1-1.
 
More results from queries before failure can be found in /dev/shm/8/log/rpl_parallel.log
 
 - saving '/dev/shm/8/log/rpl.rpl_parallel-row,xtradb/' to '/dev/shm/log/rpl.rpl_parallel-row,xtradb/'
***Warnings generated in error logs during shutdown after running tests: rpl.rpl_parallel
 
2016-08-12 23:23:27 140577332257536 [Warning] Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. Statement is unsafe because it accesses a non-transactional table after accessing a transactional table within the same transaction. Statement: INSERT INTO t1 VALUES (20)
2016-08-12 23:23:28 140697295037184 [Warning] Slave: Connection was killed Error_code: 1927
2016-08-12 23:23:28 140697293521664 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2016-08-12 23:23:29 140697294430976 [Warning] Slave: Connection was killed Error_code: 1927
2016-08-12 23:23:29 140697294734080 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2016-08-12 23:23:31 140697293521664 [Warning] Slave: Connection was killed Error_code: 1927
2016-08-12 23:23:31 140697294430976 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2016-08-12 23:23:31 140697294127872 [Warning] Slave: Connection was killed Error_code: 1927
2016-08-12 23:23:32 140697296249600 [Warning] Slave: Connection was killed Error_code: 1927
2016-08-12 23:23:34 140697366975232 [Warning] Slave: Duplicate entry '111' for key 'PRIMARY' Error_code: 1062
2016-08-12 23:23:34 140697366672128 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2016-08-12 23:23:37 140697296249600 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
2016-08-12 23:23:37 140697295643392 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
2016-08-12 23:23:37 140697295037184 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062

And:

rpl.rpl_parallel_optimistic 'stmt,xtradb' w7 [ fail ]
        Test ended at 2016-08-12 23:35:14
 
CURRENT_TEST: rpl.rpl_parallel_optimistic
mysqltest: In included file "./include/sync_with_master_gtid.inc": 
included from /home/jan/mysql/10.2/mysql-test/suite/rpl/t/rpl_parallel_optimistic.test at line 302:
At line 48: Failed to sync with master
 
The result from queries just before the failure was:
< snip >
7	5
8	7
9	8
10	8
SELECT * FROM t2 ORDER BY a;
a	b
1	0
2	0
4	4
5	5
6	5
7	7
8	7
9	8
10	10
include/save_master_gtid.inc
connection server_2;
include/start_slave.inc
include/sync_with_master_gtid.inc
Timeout in master_gtid_wait('0-1-85', 120), current slave GTID position is: 0-1-69.
 
More results from queries before failure can be found in /dev/shm/7/log/rpl_parallel_optimistic.log

Comment by Elena Stepanova [ 2016-08-21 ]

Same happens in 10.0:

http://buildbot.askmonty.org/buildbot/builders/p8-trusty-bintar-debug/builds/95/steps/test/logs/stdio

rpl.rpl_parallel 'innodb_plugin,mix'     w1 [ fail ]
        Test ended at 2016-08-14 05:19:15
 
CURRENT_TEST: rpl.rpl_parallel
mysqltest: In included file "./include/sync_with_master_gtid.inc": 
included from /var/lib/buildbot/maria-slave/p8-trusty-bintar-debug/build/mysql-test/suite/rpl/t/rpl_parallel.test at line 2371:
At line 44: Failed to sync with master
 
The result from queries just before the failure was:
< snip >
SET @old_dbug= @@SESSION.debug_dbug;
SET @commit_id= 20000;
SET SESSION debug_dbug="+d,binlog_force_commit_id";
SET SESSION debug_dbug=@old_dbug;
SELECT * FROM t7 ORDER BY a;
a	b
1	1
2	2
3	86
4	4
5	5
100	5
101	1
102	2
103	3
104	4
include/save_master_gtid.inc
include/start_slave.inc
include/sync_with_master_gtid.inc
Timeout in master_gtid_wait('1-1-3,0-1-1454,3-1-1,2-1-2', 120), current slave GTID position is: 1-1-3,0-1-1254,3-1-1,2-1-2.

I've created a separate bug for that, MDEV-10632.

Generated at Thu Feb 08 07:43:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.