[MDEV-4633] multi_source.simple test fails sporadically Created: 2013-06-10  Updated: 2020-12-25  Resolved: 2020-11-12

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.0.10, 10.0, 10.1, 10.2, 10.3, 10.4
Fix Version/s: 10.2.37, 10.3.28, 10.4.18, 10.5.9

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Andrei Elkin
Resolution: Fixed Votes: 0
Labels: slave-threads-concurrency, tests

Issue Links:
Duplicate
is duplicated by MDEV-10690 multi_source.reset_slave failed in bu... Closed
is duplicated by MDEV-22957 multi_source.multi_source_slave_alias... Closed
Relates
relates to MDEV-10042 multi_source.info_logs sporadically f... Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-deb-raring-amd64/builds/82/steps/test_3/logs/stdio

multi_source.simple                      w3 [ fail ]
        Test ended at 2013-06-08 02:47:36
 
CURRENT_TEST: multi_source.simple
--- /usr/share/mysql/mysql-test/suite/multi_source/simple.result	2013-06-07 23:29:20.000000000 +0300
+++ /run/shm/var/3/log/simple.reject	2013-06-08 02:47:36.017375264 +0300
@@ -12,7 +12,7 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Using_Gtid	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	313	mysqld-relay-bin-slave1.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			1	No	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	313	mysqld-relay-bin-slave2.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			2	No	0	1073741824	7	0	60.000	
+slave2	Reading event from the relay log	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	313	mysqld-relay-bin-slave2.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			2	No	0	1073741824	6	0	60.000	
 start all slaves;
 stop slave 'slave1';
 show slave 'slave1' status;
 
mysqltest: Result length mismatch



 Comments   
Comment by Elena Stepanova [ 2014-04-13 ]

I don't see an obvious reason why it fails, there is sync_with_master everywhere.
Also, it doesn't look like a timing issue in the sense that master issued some kind of a service message, because only State field differs, while all positions are the same.
Could be something wrong with MASTER_POS_WAIT or with status reporting in multi-master configuration?..
Needs further investigation.

Comment by Elena Stepanova [ 2016-07-24 ]

Another flavor of failure in the same test:
http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-quantal-x86/builds/4452/steps/test/logs/stdio

multi_source.simple                      w1 [ fail ]
        Test ended at 2016-07-18 12:37:57
 
CURRENT_TEST: multi_source.simple
--- /usr/local/mariadb-10.0.27-linux-i686/mysql-test/suite/multi_source/simple.result	2016-07-18 11:08:49.000000000 +0300
+++ /usr/local/mariadb-10.0.27-linux-i686/mysql-test/suite/multi_source/simple.reject	2016-07-18 12:37:56.911738307 +0300
@@ -11,7 +11,7 @@
 set default_master_connection = '';
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	313	mysqld-relay-bin-slave1.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			1			No		0	1073741824	7	0	60.000	
+slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	313	mysqld-relay-bin-slave1.000002	601	master-bin.000001	Yes	Yes							0		0	313	866	None		0	No						0	No	0		0			1			No		0	1073741824	7	0	60.000	
 slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	313	mysqld-relay-bin-slave2.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			2			No		0	1073741824	7	0	60.000	
 start all slaves;
 stop slave 'slave1';
@@ -38,7 +38,7 @@
 Last_Error	
 Skip_Counter	0
 Exec_Master_Log_Pos	313
-Relay_Log_Space	906
+Relay_Log_Space	866
 Until_Condition	None
 Until_Log_File	
 Until_Log_Pos	0
@@ -63,7 +63,7 @@
 reset slave 'slave1';
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave1			127.0.0.1	root	MYPORT_1	60		4		601		No	No							0		0	0	906	None		0	No						NULL	No	0		0			1			No		0	1073741824	7	0	60.000	
+slave1			127.0.0.1	root	MYPORT_1	60		4		601		No	No							0		0	0	866	None		0	No						NULL	No	0		0			1			No		0	1073741824	7	0	60.000	
 slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	313	mysqld-relay-bin-slave2.000002	601	master-bin.000001	Yes	Yes							0		0	313	906	None		0	No						0	No	0		0			2			No		0	1073741824	7	0	60.000	
 reset slave 'slave1' all;
 show all slaves status;

Comment by Elena Stepanova [ 2017-07-06 ]

http://buildbot.askmonty.org/buildbot/builders/kvm-deb-yakkety-amd64/builds/1153/steps/mtr/logs/stdio

multi_source.simple                      w1 [ fail ]
        Test ended at 2017-06-16 14:59:44
 
CURRENT_TEST: multi_source.simple
--- /usr/share/mysql/mysql-test/suite/multi_source/simple.result	2017-06-16 12:41:56.000000000 -0400
+++ /dev/shm/var/1/log/simple.reject	2017-06-16 14:59:43.901850653 -0400
@@ -20,7 +20,7 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave1.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			1			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	917	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 start all slaves;
 stop slave 'slave1';
 show slave 'slave1' status;
@@ -78,17 +78,17 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1			127.0.0.1	root	MYPORT_1	60		4		<relay_log_pos>		No	No							0		0	0	<relay_log_space1>	None		0	No						NULL	No	0		0			1			No				conservative	0	NULL		0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	917	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 reset slave 'slave1' all;
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	917	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 stop all slaves;
 Warnings:
 Note	1938	SLAVE 'slave2' stopped
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	1073741824	7	0	60.000	
+slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	917	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	1073741824	7	0	60.000	
 stop all slaves;
 include/reset_master_slave.inc
 disconnect slave;
 
mysqltest: Result length mismatch

Comment by Alice Sherepa [ 2017-10-10 ]

also the same way on 10.3 http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest/builds/10553/steps/test_2/logs/stdio

multi_source.simple                      w3 [ fail ]
        Test ended at 2017-10-09 17:24:46
 
CURRENT_TEST: multi_source.simple
--- /mnt/buildbot/build/mariadb-10.3.3/mysql-test/suite/multi_source/simple.result	2017-10-09 15:59:13.000000000 -0400
+++ /mnt/buildbot/build/mariadb-10.3.3/mysql-test/suite/multi_source/simple.reject	2017-10-09 17:24:46.413336221 -0400
@@ -20,7 +20,7 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave1.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			1			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	902	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 start all slaves;
 stop slave 'slave1';
 show slave 'slave1' status;
@@ -78,17 +78,17 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1			127.0.0.1	root	MYPORT_1	60		4		<relay_log_pos>		No	No							0		0	0	<relay_log_space1>	None		0	No						NULL	No	0		0			1			No				conservative	0	NULL		0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	902	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 reset slave 'slave1' all;
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	902	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	1073741824	7	0	60.000	
 stop all slaves;
 Warnings:
 Note	1938	SLAVE 'slave2' stopped
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	1073741824	7	0	60.000	
+slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	902	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	1073741824	7	0	60.000	
 stop all slaves;
 include/reset_master_slave.inc
 disconnect slave;
mysqltest: Result length mismatch

Comment by Alice Sherepa [ 2017-11-09 ]

on 10.1 http://buildbot.askmonty.org/buildbot/builders/kvm-deb-jessie-amd64/builds/3081/steps/mtr/logs/stdio

multi_source.simple                      w1 [ fail ]
        Test ended at 2017-11-08 03:23:04
 
CURRENT_TEST: multi_source.simple
--- /usr/share/mysql/mysql-test/suite/multi_source/simple.result	2017-11-08 02:30:53.000000000 -0500
+++ /dev/shm/var/1/log/simple.reject	2017-11-08 03:23:04.718998651 -0500
@@ -12,7 +12,7 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave1.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			1			No				conservative	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	869	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
 start all slaves;
 stop slave 'slave1';
 show slave 'slave1' status;
@@ -67,17 +67,17 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1			127.0.0.1	root	MYPORT_1	60		4		<relay_log_pos>		No	No							0		0	0	<relay_log_space1>	None		0	No						NULL	No	0		0			1			No				conservative	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	869	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
 reset slave 'slave1' all;
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	869	None		0	No						0	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
 stop all slaves;
 Warnings:
 Note	1938	SLAVE 'slave2' stopped
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						NULL	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
+slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	869	None		0	No						NULL	No	0		0			2			No				conservative	0	1073741824	7	0	60.000	
 stop all slaves;
 include/reset_master_slave.inc
 include/reset_master_slave.inc
 
mysqltest: Result length mismatch

Comment by Elena Stepanova [ 2019-01-24 ]

Still failing on different versions.

Comment by Alice Sherepa [ 2020-07-10 ]

http://buildbot.askmonty.org/buildbot/builders/kvm-deb-xenial-amd64/builds/8610/steps/mtr/logs/stdio

10.4

multi_source.simple                      w2 [ fail ]
        Test ended at 2020-07-08 18:04:32
 
CURRENT_TEST: multi_source.simple
--- /usr/share/mysql/mysql-test/suite/multi_source/simple.result	2020-07-08 16:48:01.000000000 -0400
+++ /dev/shm/var/2/log/simple.reject	2020-07-08 18:04:31.897651757 -0400
@@ -20,7 +20,7 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Slave_DDL_Groups	Slave_Non_Transactional_Groups	Slave_Transactional_Groups	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_1	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave1.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			1			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	694	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
 start all slaves;
 stop slave 'slave1';
 show slave 'slave1' status;
@@ -81,17 +81,17 @@
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Slave_DDL_Groups	Slave_Non_Transactional_Groups	Slave_Transactional_Groups	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
 slave1			127.0.0.1	root	MYPORT_1	60		4		<relay_log_pos>		No	No							0		0	0	<relay_log_space1>	None		0	No						NULL	No	0		0			1			No				conservative	0	NULL		0	0	0	0	1073741824	7	0	60.000	
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	694	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
 reset slave 'slave1' all;
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Slave_DDL_Groups	Slave_Non_Transactional_Groups	Slave_Transactional_Groups	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
+slave2	Slave has read all relay log; waiting for the slave I/O thread to update it	Waiting for master to send event	127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	Yes	Yes							0		0	<read_master_log_pos>	694	None		0	No						0	No	0		0			2			No				conservative	0	NULL	Slave has read all relay log; waiting for the slave I/O thread to update it	0	0	0	0	1073741824	7	0	60.000	
 stop all slaves;
 Warnings:
 Note	1938	SLAVE 'slave2' stopped
 show all slaves status;
 Connection_name	Slave_SQL_State	Slave_IO_State	Master_Host	Master_User	Master_Port	Connect_Retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_Do_DB	Replicate_Ignore_DB	Replicate_Do_Table	Replicate_Ignore_Table	Replicate_Wild_Do_Table	Replicate_Wild_Ignore_Table	Last_Errno	Last_Error	Skip_Counter	Exec_Master_Log_Pos	Relay_Log_Space	Until_Condition	Until_Log_File	Until_Log_Pos	Master_SSL_Allowed	Master_SSL_CA_File	Master_SSL_CA_Path	Master_SSL_Cert	Master_SSL_Cipher	Master_SSL_Key	Seconds_Behind_Master	Master_SSL_Verify_Server_Cert	Last_IO_Errno	Last_IO_Error	Last_SQL_Errno	Last_SQL_Error	Replicate_Ignore_Server_Ids	Master_Server_Id	Master_SSL_Crl	Master_SSL_Crlpath	Using_Gtid	Gtid_IO_Pos	Replicate_Do_Domain_Ids	Replicate_Ignore_Domain_Ids	Parallel_Mode	SQL_Delay	SQL_Remaining_Delay	Slave_SQL_Running_State	Slave_DDL_Groups	Slave_Non_Transactional_Groups	Slave_Transactional_Groups	Retried_transactions	Max_relay_log_size	Executed_log_entries	Slave_received_heartbeats	Slave_heartbeat_period	Gtid_Slave_Pos
-slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	<relay_log_space1>	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	0	0	0	1073741824	7	0	60.000	
+slave2			127.0.0.1	root	MYPORT_2	60	master-bin.000001	<read_master_log_pos>	mysqld-relay-bin-slave2.000002	<relay_log_pos>	master-bin.000001	No	No							0		0	<read_master_log_pos>	694	None		0	No						NULL	No	0		0			2			No				conservative	0	NULL		0	0	0	0	1073741824	7	0	60.000	
 stop all slaves;
 include/reset_master_slave.inc
 disconnect slave;
 
mysqltest: Result length mismatch

Comment by Sujatha Sivakumar (Inactive) [ 2020-08-25 ]

The issue seems to related to 'rli->log_space_total' total computation. Still analysis is in progress.

Comment by Sujatha Sivakumar (Inactive) [ 2020-08-27 ]

Writes to 'rli->log_space_total' needs to be synchronized. All modifications to 'rli->log_space_total' should be performed by holding 'rli->log_space_lock'. But IO thread doesn't acquire this mutex while writing events to relay log.
Hence there is a race condition between SQL THREAD and IO THREAD, when both try to modify the same variable. SQL_THREAD is trying to decrement 'rli->log_space_total' in 'purge_first_log' and IO_THREAD is trying to increment the 'rli->log_space_total' in 'queue_event' simultaneously . Hence test occasionally fails with result mismatch.

Comment by Sujatha Sivakumar (Inactive) [ 2020-08-28 ]

Hello Andrei,

Can you please review the fix for MDEV-4633.

Patch: https://github.com/MariaDB/server/commit/e4fa0c805adf06c637cc3867427ca529b40e19ce

BuildBot Test: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha

Thank you.

Comment by Sujatha Sivakumar (Inactive) [ 2020-09-04 ]

Hello Elkin

Please find the 10.4 specific patch, which converts rli->log_space_total to atomic type.

https://github.com/MariaDB/server/commit/169d05ef80927bfa5e5fe434506b02ee5d08284b

Thank you.

Comment by Sujatha Sivakumar (Inactive) [ 2020-09-08 ]

Hello Elkin

Please find the 10.1 patch, I have addressed your review comments.
Converted 'rli->log_space_total' to atomic type.

https://github.com/MariaDB/server/commit/5d9386892b58477c4e28de3e40d930b44f5b42d4
BuildBot: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha

Please review it.

Comment by Sujatha Sivakumar (Inactive) [ 2020-09-21 ]

Hello Elkin,

Please find the final changes for MDEV-4633.

10.1 path: https://github.com/MariaDB/server/commit/5ca4b1a5dc52db4bc8bfb117edf6d3431b8e1a9c
10.4 path: https://github.com/MariaDB/server/commit/169d05ef80927bfa5e5fe434506b02ee5d08284b

Thank you

Comment by Sujatha Sivakumar (Inactive) [ 2020-11-12 ]

Patch is approved by Andrei.

Pushed the change into 10.2.37. Changes are merged till 10.4.

Generated at Thu Feb 08 06:57:54 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.