Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-10550

Parallel replication can't sync with master in InnoDB 5.7 (branch bb-10.2-jan)

Details

    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

      Attachments

        Issue Links

          Activity

            jplindst Jan Lindström (Inactive) added a comment - - edited

            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
            

            jplindst Jan Lindström (Inactive) added a comment - - edited 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
            elenst Elena Stepanova added a comment - - edited

            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.

            elenst Elena Stepanova added a comment - - edited 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 .

            People

              monty Michael Widenius
              jplindst Jan Lindström (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.