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

rpl.rpl_mariadb_slave_capability fails sporadically in buildbot

Details

    Description

      By now happened 3 times, on 10.1 and 10.2, first occurrence in May 2016 (so it might be relatively new).

      Last occurrence:
      http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/6073/steps/test_2/logs/stdio

      rpl.rpl_mariadb_slave_capability 'row,xtradb' w1 [ fail ]
              Test ended at 2016-10-10 19:56:44
       
      CURRENT_TEST: rpl.rpl_mariadb_slave_capability
      --- /mnt/buildbot/build/mariadb-10.1.19/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result	2016-10-10 16:00:32.000000000 +0300
      +++ /mnt/buildbot/build/mariadb-10.1.19/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.reject	2016-10-10 19:56:44.000000000 +0300
      @@ -30,6 +30,7 @@
       1
       include/show_events.inc
       Log_name	Pos	Event_type	Server_id	End_log_pos	Info
      +slave-relay-bin.000005	#	Query	#	#	# Dummy
       slave-relay-bin.000005	#	Query	#	#	BEGIN
       slave-relay-bin.000005	#	User var	#	#	@`!dummyvar`=NULL
       slave-relay-bin.000005	#	Table_map	#	#	table_id: # (test.t1)
      @@ -39,7 +40,6 @@
       slave-relay-bin.000005	#	Query	#	#	# Dummy event replacing event type 160 that slave cannot handle.                                                                                                         
       slave-relay-bin.000005	#	Table_map	#	#	table_id: # (test.t1)
       slave-relay-bin.000005	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
      -slave-relay-bin.000005	#	Query	#	#	COMMIT
       set @@global.debug_dbug= @old_slave_dbug;
       # Test dummy event is checksummed correctly.
       set @@global.binlog_checksum = CRC32;
       
      mysqltest: Result length mismatch
      

      Attachments

        Issue Links

          Activity

            Also fails sometimes with:

            https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10460

            10.6 a55b951e6

            rpl.rpl_mariadb_slave_capability 'innodb,row' w3 [ fail ]
                    Test ended at 2023-03-16 17:02:49
             
            CURRENT_TEST: rpl.rpl_mariadb_slave_capability
            --- /usr/share/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result	2023-03-16 15:39:35.000000000 +0000
            +++ /dev/shm/var/3/log/rpl_mariadb_slave_capability.reject	2023-03-16 17:02:48.667830165 +0000
            @@ -23,6 +23,7 @@
             INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1);
             include/show_binlog_events.inc
             Log_name	Pos	Event_type	Server_id	End_log_pos	Info
            +master-bin.000002	#	Binlog_checkpoint	#	#	master-bin.000002
             master-bin.000002	#	Gtid	#	#	BEGIN GTID #-#-#
             master-bin.000002	#	Annotate_rows	#	#	DELETE FROM t1
             master-bin.000002	#	Table_map	#	#	table_id: # (test.t1)
            @@ -32,7 +33,6 @@
             master-bin.000002	#	Annotate_rows	#	#	INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1)
             master-bin.000002	#	Table_map	#	#	table_id: # (test.t1)
             master-bin.000002	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
            -master-bin.000002	#	Query	#	#	COMMIT
             connection slave;
             connection slave;
             SELECT * FROM t1;
            @@ -40,6 +40,7 @@
             1
             include/show_events.inc
             Log_name	Pos	Event_type	Server_id	End_log_pos	Info
            +slave-relay-bin.000005	#	Query	#	#	# Dummy
             slave-relay-bin.000005	#	Query	#	#	BEGIN
             slave-relay-bin.000005	#	Annotate_rows	#	#	DELETE FROM t1
             slave-relay-bin.000005	#	Table_map	#	#	table_id: # (test.t1)
            @@ -49,7 +50,6 @@
             slave-relay-bin.000005	#	Annotate_rows	#	#	INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1)
             slave-relay-bin.000005	#	Table_map	#	#	table_id: # (test.t1)
             slave-relay-bin.000005	#	Write_rows_v1	#	#	table_id: # flags: STMT_END_F
            -slave-relay-bin.000005	#	Query	#	#	COMMIT
             set @@global.debug_dbug= @old_dbug;
             # Test dummy event is checksummed correctly.
             connection master;
             
            mysqltest: Result length mismatch
            

            angelique.sklavounos Angelique Sklavounos (Inactive) added a comment - Also fails sometimes with: https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10460 10.6 a55b951e6 rpl.rpl_mariadb_slave_capability 'innodb,row' w3 [ fail ] Test ended at 2023-03-16 17:02:49   CURRENT_TEST: rpl.rpl_mariadb_slave_capability --- /usr/share/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result 2023-03-16 15:39:35.000000000 +0000 +++ /dev/shm/var/3/log/rpl_mariadb_slave_capability.reject 2023-03-16 17:02:48.667830165 +0000 @@ -23,6 +23,7 @@ INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1); include/show_binlog_events.inc Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000002 # Binlog_checkpoint # # master-bin.000002 master-bin.000002 # Gtid # # BEGIN GTID #-#-# master-bin.000002 # Annotate_rows # # DELETE FROM t1 master-bin.000002 # Table_map # # table_id: # (test.t1) @@ -32,7 +33,6 @@ master-bin.000002 # Annotate_rows # # INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1) master-bin.000002 # Table_map # # table_id: # (test.t1) master-bin.000002 # Write_rows_v1 # # table_id: # flags: STMT_END_F -master-bin.000002 # Query # # COMMIT connection slave; connection slave; SELECT * FROM t1; @@ -40,6 +40,7 @@ 1 include/show_events.inc Log_name Pos Event_type Server_id End_log_pos Info +slave-relay-bin.000005 # Query # # # Dummy slave-relay-bin.000005 # Query # # BEGIN slave-relay-bin.000005 # Annotate_rows # # DELETE FROM t1 slave-relay-bin.000005 # Table_map # # table_id: # (test.t1) @@ -49,7 +50,6 @@ slave-relay-bin.000005 # Annotate_rows # # INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1) slave-relay-bin.000005 # Table_map # # table_id: # (test.t1) slave-relay-bin.000005 # Write_rows_v1 # # table_id: # flags: STMT_END_F -slave-relay-bin.000005 # Query # # COMMIT set @@global.debug_dbug= @old_dbug; # Test dummy event is checksummed correctly. connection master;   mysqltest: Result length mismatch
            marko Marko Mäkelä added a comment - Still fails on a 10.5-based branch: https://buildbot.mariadb.org/#/builders/572/builds/4246

            Just a missing --source include/wait_for_binlog_checkpoint.inc, I'll fix.
            Here's how to reproduce reliably:

            diff --git a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test
            index 046a65f77db..049dd36a860 100644
            --- a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test
            +++ b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test
            @@ -39,6 +39,7 @@ SET SESSION binlog_annotate_row_events = ON;
             let $binlog_file= query_get_value(SHOW MASTER STATUS, File, 1);
             let $binlog_start= query_get_value(SHOW MASTER STATUS, Position, 1);
             # A short event, to test when we need to use user_var_event for dummy event.
            +--sleep 0.1
             DELETE FROM t1;
             INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1);
             let $binlog_limit= 0, 10;
            diff --git a/sql/log.cc b/sql/log.cc
            index 59730c3205a..48269e92a0c 100644
            --- a/sql/log.cc
            +++ b/sql/log.cc
            @@ -10210,6 +10210,7 @@ binlog_background_thread(void *arg __attribute__((unused)))
                   /* Grab next pointer first, as mark_xid_done() may free the element. */
                   next= queue->next_in_queue;
                   queue->notify_count= 0;
            +my_sleep(20000);
                   for (long i= 0; i <= count; i++)
                     mysql_bin_log.mark_xid_done(queue->binlog_id, true);
                   queue= next;
            

            knielsen Kristian Nielsen added a comment - Just a missing --source include/wait_for_binlog_checkpoint.inc, I'll fix. Here's how to reproduce reliably: diff --git a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test index 046a65f77db..049dd36a860 100644 --- a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test +++ b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test @@ -39,6 +39,7 @@ SET SESSION binlog_annotate_row_events = ON; let $binlog_file= query_get_value(SHOW MASTER STATUS, File, 1); let $binlog_start= query_get_value(SHOW MASTER STATUS, Position, 1); # A short event, to test when we need to use user_var_event for dummy event. +--sleep 0.1 DELETE FROM t1; INSERT INTO t1 /* A comment just to make the annotate event sufficiently long that the dummy event will need to get padded with spaces so that we can test that this works */ VALUES(1); let $binlog_limit= 0, 10; diff --git a/sql/log.cc b/sql/log.cc index 59730c3205a..48269e92a0c 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -10210,6 +10210,7 @@ binlog_background_thread(void *arg __attribute__((unused))) /* Grab next pointer first, as mark_xid_done() may free the element. */ next= queue->next_in_queue; queue->notify_count= 0; +my_sleep(20000); for (long i= 0; i <= count; i++) mysql_bin_log.mark_xid_done(queue->binlog_id, true); queue= next;

            Pushed to 10.4

            knielsen Kristian Nielsen added a comment - Pushed to 10.4

            People

              knielsen Kristian Nielsen
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.