[MDEV-14507] binlog_encryption.rpl_ssl fails with timeouts on SLES 11.4 Created: 2017-11-27  Updated: 2023-11-29  Resolved: 2023-11-29

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.1
Fix Version/s: N/A

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-zyp-sles114-x86/builds/825/steps/mtr/logs/stdio

binlog_encryption.rpl_ssl 'row'          w1 [ fail ]
        Test ended at 2017-11-24 00:56:30
 
CURRENT_TEST: binlog_encryption.rpl_ssl
=== SHOW MASTER STATUS ===
---- 1. ----
File	slave-bin.000001
Position	952
Binlog_Do_DB	
Binlog_Ignore_DB	
==========================
 
=== SHOW SLAVE STATUS ===
---- 1. ----
Slave_IO_State	Reconnecting after a failed master event read
Master_Host	127.0.0.1
Master_User	replssl
Master_Port	16020
Connect_Retry	1
Master_Log_File	master-bin.000001
Read_Master_Log_Pos	989
Relay_Log_File	slave-relay-bin.000002
Relay_Log_Pos	720
Relay_Master_Log_File	master-bin.000001
Slave_IO_Running	Connecting
Slave_SQL_Running	Yes
Replicate_Do_DB	
Replicate_Ignore_DB	
Replicate_Do_Table	
Replicate_Ignore_Table	
Replicate_Wild_Do_Table	
Replicate_Wild_Ignore_Table	
Last_Errno	0
Last_Error	
Skip_Counter	0
Exec_Master_Log_Pos	989
Relay_Log_Space	1018
Until_Condition	None
Until_Log_File	
Until_Log_Pos	0
Master_SSL_Allowed	Yes
Master_SSL_CA_File	/usr/share/mysql-test/std_data/cacert.pem
Master_SSL_CA_Path	
Master_SSL_Cert	/usr/share/mysql-test/std_data/client-cert.pem
Master_SSL_Cipher	
Master_SSL_Key	/usr/share/mysql-test/std_data/client-key.pem
Seconds_Behind_Master	
Master_SSL_Verify_Server_Cert	No
Last_IO_Errno	0
Last_IO_Error	
Last_SQL_Errno	0
Last_SQL_Error	
Replicate_Ignore_Server_Ids	
Master_Server_Id	1
Master_SSL_Crl	/usr/share/mysql-test/std_data/cacert.pem
Master_SSL_Crlpath	
Using_Gtid	No
Gtid_IO_Pos	
Replicate_Do_Domain_Ids	
Replicate_Ignore_Domain_Ids	
Parallel_Mode	conservative
=========================
 
=== SHOW PROCESSLIST ===
---- 1. ----
Id	13
User	root
Host	localhost:42213
db	test
Command	Sleep
Time	300
State	
Info	
Progress	0.000
---- 2. ----
Id	14
User	root
Host	localhost:42214
db	test
Command	Sleep
Time	300
State	
Info	
Progress	0.000
---- 3. ----
Id	17
User	root
Host	localhost:42220
db	test
Command	Query
Time	0
State	init
Info	SHOW PROCESSLIST
Progress	0.000
---- 4. ----
Id	18
User	root
Host	localhost:42221
db	test
Command	Sleep
Time	300
State	
Info	
Progress	0.000
---- 5. ----
Id	21
User	system user
Host	
db	
Command	Connect
Time	300
State	Reconnecting after a failed master event read
Info	
Progress	0.000
---- 6. ----
Id	22
User	system user
Host	
db	
Command	Connect
Time	300
State	Slave has read all relay log; waiting for the slave I/O thread to update it
Info	
Progress	0.000
========================
 
analyze: sync_with_master
mysqltest: In included file "./extra/rpl_tests/rpl_ssl.inc": 
included from /usr/share/mysql-test/suite/binlog_encryption/rpl_ssl.test at line 2:
At line 78: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 1171, 300, '')' returned -1 indicating timeout after 300 seconds
 
The result from queries just before the failure was:
< snip >
master_ssl=1,
master_ssl_ca ='MYSQL_TEST_DIR/std_data/cacert.pem',
master_ssl_cert='MYSQL_TEST_DIR/std_data/client-cert.pem',
master_ssl_key='MYSQL_TEST_DIR/std_data/client-key.pem';
start slave;
insert into t1 values(1);
select * from t1;
t
1
Master_SSL_Allowed = 'Yes'
Master_SSL_CA_Path = ''
Master_SSL_CA_File = 'MYSQL_TEST_DIR/std_data/cacert.pem'
Master_SSL_Cert = 'MYSQL_TEST_DIR/std_data/client-cert.pem'
Master_SSL_Key = 'MYSQL_TEST_DIR/std_data/client-key.pem'
include/check_slave_is_running.inc
STOP SLAVE;
select * from t1;
t
1
insert into t1 values (NULL);
 
More results from queries before failure can be found in /dev/shm/var/1/log/rpl_ssl.log
 
 
 == /dev/shm/var/1/tmp/analyze-sync_with_master-mysqld.2.err ==
 
############################## default ##############################
 
**** SHOW WARNINGS on default ****
SHOW WARNINGS;
Level	Code	Message
 
**** SELECT replication-related variables on default ****
SELECT NOW(), @@SERVER_ID;
NOW()	@@SERVER_ID
2017-11-24 00:54:29	2
 
**** SHOW SLAVE STATUS on default ****
SHOW SLAVE STATUS;
Slave_IO_State	Reconnecting after a failed master event read
Master_Host	127.0.0.1
Master_User	replssl
Master_Port	16020
Connect_Retry	1
Master_Log_File	master-bin.000001
Read_Master_Log_Pos	989
Relay_Log_File	slave-relay-bin.000002
Relay_Log_Pos	720
Relay_Master_Log_File	master-bin.000001
Slave_IO_Running	Connecting
Slave_SQL_Running	Yes
Replicate_Do_DB	
Replicate_Ignore_DB	
Replicate_Do_Table	
Replicate_Ignore_Table	
Replicate_Wild_Do_Table	
Replicate_Wild_Ignore_Table	
Last_Errno	0
Last_Error	
Skip_Counter	0
Exec_Master_Log_Pos	989
Relay_Log_Space	1018
Until_Condition	None
Until_Log_File	
Until_Log_Pos	0
Master_SSL_Allowed	Yes
Master_SSL_CA_File	/usr/share/mysql-test/std_data/cacert.pem
Master_SSL_CA_Path	
Master_SSL_Cert	/usr/share/mysql-test/std_data/client-cert.pem
Master_SSL_Cipher	
Master_SSL_Key	/usr/share/mysql-test/std_data/client-key.pem
Seconds_Behind_Master	NULL
Master_SSL_Verify_Server_Cert	No
Last_IO_Errno	0
Last_IO_Error	
Last_SQL_Errno	0
Last_SQL_Error	
Replicate_Ignore_Server_Ids	
Master_Server_Id	1
Master_SSL_Crl	/usr/share/mysql-test/std_data/cacert.pem
Master_SSL_Crlpath	
Using_Gtid	No
Gtid_IO_Pos	
Replicate_Do_Domain_Ids	
Replicate_Ignore_Domain_Ids	
Parallel_Mode	conservative
 
**** SHOW MASTER STATUS on default ****
SHOW MASTER STATUS;
File	slave-bin.000001
Position	952
Binlog_Do_DB	
Binlog_Ignore_DB	
 
**** SHOW SLAVE HOSTS on default ****
SHOW SLAVE HOSTS;
 
**** SHOW PROCESSLIST on default ****
SHOW PROCESSLIST;
Id	User	Host	db	Command	Time	State	Info	Progress
21	system user		NULL	Connect	300	Reconnecting after a failed master event read	NULL	0.000
22	system user		NULL	Connect	300	Slave has read all relay log; waiting for the slave I/O thread to update it	NULL	0.000
23	root	localhost	NULL	Query	0	init	SHOW PROCESSLIST	0.000
 
**** SHOW BINARY LOGS on default ****
SHOW BINARY LOGS;
Log_name	File_size
slave-bin.000001	952
 
**** SHOW BINLOG EVENTS on default ****
binlog_name = 'slave-bin.000001'
SHOW BINLOG EVENTS IN 'slave-bin.000001';
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
slave-bin.000001	4	Format_desc	2	249	Server ver: 10.1.30-MariaDB, Binlog ver: 4
slave-bin.000001	249	Gtid_list	2	274	[]
slave-bin.000001	274	Binlog_checkpoint	2	313	slave-bin.000001
slave-bin.000001	313	Gtid	1	351	GTID 0-1-1
slave-bin.000001	351	Query	1	443	use `test`; create user replssl@localhost
slave-bin.000001	443	Gtid	1	481	GTID 0-1-2
slave-bin.000001	481	Query	1	623	use `test`; grant replication slave on *.* to replssl@localhost require ssl
slave-bin.000001	623	Gtid	1	661	GTID 0-1-3
slave-bin.000001	661	Query	1	770	use `test`; create table t1 (t int auto_increment, KEY(t))
slave-bin.000001	770	Gtid	1	808	BEGIN GTID 0-1-4
slave-bin.000001	808	Table_map	1	849	table_id: 43 (test.t1)
slave-bin.000001	849	Write_rows_v1	1	883	table_id: 43 flags: STMT_END_F
slave-bin.000001	883	Query	1	952	COMMIT
 
**** SHOW RELAYLOG EVENTS on default ****
relaylog_name = 'slave-relay-bin.000002'
SHOW RELAYLOG EVENTS IN 'slave-relay-bin.000002';
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
slave-relay-bin.000002	4	Format_desc	2	249	Server ver: 10.1.30-MariaDB, Binlog ver: 4
slave-relay-bin.000002	249	Rotate	1	0	master-bin.000001;pos=807
slave-relay-bin.000002	293	Format_desc	1	0	Server ver: 10.1.30-MariaDB, Binlog ver: 4
slave-relay-bin.000002	538	Gtid	1	845	BEGIN GTID 0-1-4
slave-relay-bin.000002	576	Table_map	1	886	table_id: 45 (test.t1)
slave-relay-bin.000002	617	Write_rows_v1	1	920	table_id: 45 flags: STMT_END_F
slave-relay-bin.000002	651	Query	1	989	COMMIT
 
 == /dev/shm/var/1/tmp/analyze-sync_with_master-mysqld.1.err ==
mysqltest: Could not open connection 'default': 2013 Lost connection to MySQL server at 'waiting for initial communication packet', system error: 110 "Connection timed out"

http://buildbot.askmonty.org/buildbot/builders/kvm-zyp-sles114-amd64/builds/834/steps/mtr/logs/stdio

binlog_encryption.rpl_ssl 'row'          w4 [ fail ]  timeout after 900 seconds
        Test ended at 2017-11-24 18:46:10
 
Test case timeout after 900 seconds
 
== /dev/shm/var/4/log/rpl_ssl.log == 
1
Master_SSL_Allowed = 'Yes'
Master_SSL_CA_Path = ''
Master_SSL_CA_File = 'MYSQL_TEST_DIR/std_data/cacert.pem'
Master_SSL_Cert = 'MYSQL_TEST_DIR/std_data/client-cert.pem'
Master_SSL_Key = 'MYSQL_TEST_DIR/std_data/client-key.pem'
include/check_slave_is_running.inc
STOP SLAVE;
select * from t1;
t
1
insert into t1 values (NULL);
include/wait_for_slave_to_start.inc
Master_SSL_Allowed = 'Yes'
Master_SSL_CA_Path = ''
Master_SSL_CA_File = 'MYSQL_TEST_DIR/std_data/cacert.pem'
Master_SSL_Cert = 'MYSQL_TEST_DIR/std_data/client-cert.pem'
Master_SSL_Key = 'MYSQL_TEST_DIR/std_data/client-key.pem'
include/check_slave_is_running.inc
drop user replssl@localhost;
 
 == /dev/shm/var/4/tmp/analyze-timeout-mysqld.1.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/dev/shm/var/tmp/4/mysqld.1.sock' (111 "Connection refused")
 
 == /dev/shm/var/4/tmp/analyze-timeout-mysqld.2.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local MySQL server through socket '/dev/shm/var/tmp/4/mysqld.2.sock' (111 "Connection refused")


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