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

rpl.rpl_start_stop_slave failed in buildbot with timeout in sync

    XMLWordPrintable

Details

    • Bug
    • Status: Open (View Workflow)
    • Minor
    • Resolution: Unresolved
    • 10.0, 10.1, 10.2, 10.3, 10.4, 10.5
    • 10.4, 10.5
    • Tests
    • None

    Description

      http://buildbot.askmonty.org/buildbot/builders/qa-kvm-linux/builds/1772/steps/stable_tests/logs/stdio

      rpl.rpl_start_stop_slave 'row'           w3 [ fail ]
              Test ended at 2017-08-09 18:21:43
       
      CURRENT_TEST: rpl.rpl_start_stop_slave
      === SHOW MASTER STATUS ===
      ---- 1. ----
      File	slave-bin.000001
      Position	328
      Binlog_Do_DB	
      Binlog_Ignore_DB	
      ==========================
       
      === SHOW SLAVE STATUS ===
      ---- 1. ----
      Slave_IO_State	
      Master_Host	127.0.0.1
      Master_User	root
      Master_Port	16020
      Connect_Retry	1
      Master_Log_File	master-bin.000001
      Read_Master_Log_Pos	329
      Relay_Log_File	slave-relay-bin.000002
      Relay_Log_Pos	629
      Relay_Master_Log_File	master-bin.000001
      Slave_IO_Running	No
      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	329
      Relay_Log_Space	938
      Until_Condition	None
      Until_Log_File	
      Until_Log_Pos	0
      Master_SSL_Allowed	No
      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	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	
      Master_SSL_Crlpath	
      Using_Gtid	No
      Gtid_IO_Pos	
      Replicate_Do_Domain_Ids	
      Replicate_Ignore_Domain_Ids	
      Parallel_Mode	conservative
      SQL_Delay	0
      SQL_Remaining_Delay	
      Slave_SQL_Running_State	Slave has read all relay log; waiting for the slave I/O thread to update it
      =========================
       
      === SHOW PROCESSLIST ===
      ---- 1. ----
      Id	1
      User	system user
      Host	
      db	
      Command	Daemon
      Time	
      State	
      Info	
      Progress	0.000
      ---- 2. ----
      Id	2
      User	system user
      Host	
      db	
      Command	Daemon
      Time	
      State	
      Info	
      Progress	0.000
      ---- 3. ----
      Id	3
      User	system user
      Host	
      db	
      Command	Daemon
      Time	
      State	
      Info	
      Progress	0.000
      ---- 4. ----
      Id	4
      User	system user
      Host	
      db	
      Command	Daemon
      Time	
      State	InnoDB purge worker
      Info	
      Progress	0.000
      ---- 5. ----
      Id	5
      User	system user
      Host	
      db	
      Command	Daemon
      Time	
      State	InnoDB shutdown handler
      Info	
      Progress	0.000
      ---- 6. ----
      Id	10
      User	root
      Host	localhost:58041
      db	test
      Command	Sleep
      Time	300
      State	
      Info	
      Progress	0.000
      ---- 7. ----
      Id	11
      User	root
      Host	localhost:58042
      db	test
      Command	Sleep
      Time	300
      State	
      Info	
      Progress	0.000
      ---- 8. ----
      Id	13
      User	system user
      Host	
      db	
      Command	Slave_SQL
      Time	300
      State	Slave has read all relay log; waiting for the slave I/O thread to update it
      Info	
      Progress	0.000
      ---- 9. ----
      Id	14
      User	root
      Host	localhost:58049
      db	test
      Command	Query
      Time	0
      State	init
      Info	SHOW PROCESSLIST
      Progress	0.000
      ---- 10. ----
      Id	15
      User	root
      Host	localhost:58050
      db	test
      Command	Sleep
      Time	300
      State	
      Info	
      Progress	0.000
      ========================
       
      analyze: sync_with_master
      mysqltest: At line 59: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 473, 300, '')' returned -1 indicating timeout after 300 seconds
       
      The result from queries just before the failure was:
      include/master-slave.inc
      [connection master]
      connection slave;
      set @time_before_kill := (select CURRENT_TIMESTAMP);
      [Time before the query]
      [Connection ID of the slave I/O thread found]
      kill <connection_id>;
      set @time_after_kill := (select CURRENT_TIMESTAMP);
      [Time after the query]
      [Killing of the slave IO thread was successful]
      START SLAVE IO_THREAD;
      Warnings:
      Note	1254	Slave is already running
      connection master;
      create table t1 (a int primary key);
       
       
       == /home/buildbot/build/mysql-test/var/3/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-08-09 18:21:42	2
       
      **** SHOW SLAVE STATUS on default ****
      SHOW SLAVE STATUS;
      Slave_IO_State	
      Master_Host	127.0.0.1
      Master_User	root
      Master_Port	16020
      Connect_Retry	1
      Master_Log_File	master-bin.000001
      Read_Master_Log_Pos	329
      Relay_Log_File	slave-relay-bin.000002
      Relay_Log_Pos	629
      Relay_Master_Log_File	master-bin.000001
      Slave_IO_Running	No
      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	329
      Relay_Log_Space	938
      Until_Condition	None
      Until_Log_File	
      Until_Log_Pos	0
      Master_SSL_Allowed	No
      Master_SSL_CA_File	
      Master_SSL_CA_Path	
      Master_SSL_Cert	
      Master_SSL_Cipher	
      Master_SSL_Key	
      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	
      Master_SSL_Crlpath	
      Using_Gtid	No
      Gtid_IO_Pos	
      Replicate_Do_Domain_Ids	
      Replicate_Ignore_Domain_Ids	
      Parallel_Mode	conservative
      SQL_Delay	0
      SQL_Remaining_Delay	NULL
      Slave_SQL_Running_State	Slave has read all relay log; waiting for the slave I/O thread to update it
       
      **** SHOW MASTER STATUS on default ****
      SHOW MASTER STATUS;
      File	slave-bin.000001
      Position	328
      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
      1	system user		NULL	Daemon	NULL		NULL	0.000
      2	system user		NULL	Daemon	NULL		NULL	0.000
      3	system user		NULL	Daemon	NULL		NULL	0.000
      4	system user		NULL	Daemon	NULL	InnoDB purge worker	NULL	0.000
      5	system user		NULL	Daemon	NULL	InnoDB shutdown handler	NULL	0.000
      13	system user		NULL	Slave_SQL	300	Slave has read all relay log; waiting for the slave I/O thread to update it	NULL	0.000
      16	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	328
       
      **** 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	256	Server ver: 10.2.8-MariaDB-debug-log, Binlog ver: 4
      slave-bin.000001	256	Gtid_list	2	285	[]
      slave-bin.000001	285	Binlog_checkpoint	2	328	slave-bin.000001
       
      **** 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	256	Server ver: 10.2.8-MariaDB-debug-log, Binlog ver: 4
      slave-relay-bin.000002	256	Rotate	1	0	master-bin.000001;pos=4
      slave-relay-bin.000002	304	Format_desc	1	256	Server ver: 10.2.8-MariaDB-debug-log, Binlog ver: 4
      slave-relay-bin.000002	556	Gtid_list	1	285	[]
      slave-relay-bin.000002	585	Binlog_checkpoint	1	329	master-bin.000001
      connection default;
       
       == /home/buildbot/build/mysql-test/var/3/tmp/analyze-sync_with_master-mysqld.1.err ==
       
      ############################## default ##############################
       
      **** SHOW WARNINGS on default ****
      SHOW WARNINGS;
      Level	Code	Message
      Error	1160	Got an error writing communication packets
      Error	1105	
       
      **** SELECT replication-related variables on default ****
      SELECT NOW(), @@SERVER_ID;
      NOW()	@@SERVER_ID
      2017-08-09 18:21:42	1
       
      **** SHOW SLAVE STATUS on default ****
      SHOW SLAVE STATUS;
       
      **** SHOW MASTER STATUS on default ****
      SHOW MASTER STATUS;
      File	master-bin.000001
      Position	473
      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
      11	root	localhost	NULL	Query	0	init	SHOW PROCESSLIST	0.000
       
      **** SHOW BINARY LOGS on default ****
      SHOW BINARY LOGS;
      Log_name	File_size
      master-bin.000001	473
       
      **** SHOW BINLOG EVENTS on default ****
      binlog_name = 'master-bin.000001'
      SHOW BINLOG EVENTS IN 'master-bin.000001';
      Log_name	Pos	Event_type	Server_id	End_log_pos	Info
      master-bin.000001	4	Format_desc	1	256	Server ver: 10.2.8-MariaDB-debug-log, Binlog ver: 4
      master-bin.000001	256	Gtid_list	1	285	[]
      master-bin.000001	285	Binlog_checkpoint	1	329	master-bin.000001
      master-bin.000001	329	Gtid	1	371	GTID 0-1-1
      master-bin.000001	371	Query	1	473	use `test`; create table t1 (a int primary key)
       
      **** SHOW RELAYLOG EVENTS on default ****
      relaylog_name = 'No such row'
      SHOW RELAYLOG EVENTS IN 'No such row';
      Log_name	Pos	Event_type	Server_id	End_log_pos	Info
      connection default;
      

      Attachments

        Activity

          People

            Elkin Andrei Elkin
            elenst Elena Stepanova
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

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