MySQL Bugs: #90822: timed auto send “start slave”

Bug #90822	timed auto send “start slave”
Submitted:	10 May 2018 10:31	Modified:	14 May 2018 3:39
Reporter:	仁刚谭	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.7.18	OS:	Red Hat (6.8)
Assigned to:	MySQL Verification Team	CPU Architecture:	x86
Tags:	replication, start slave

Description:
slave auto send "start slave"

slave 1:
2018-05-10T10:27:42.113461Z 34 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2018-05-10T10:27:52.133083Z 34 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.

slave 2:
2018-05-10T10:42:01.925348Z 8 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2018-05-10T10:43:04.001730Z 8 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.

master:
2018-05-10T10:28:53.986934Z 142 [Note] While initializing dump thread for slave with UUID <638fd4d4-3eee-11e8-ae18-005056807f1c>, found a zombie dump thread with the same UUID. Master is killing the zombie dump thread(141).
2018-05-10T10:28:53.987052Z 142 [Note] Start binlog_dump to master_thread_id(142) slave_server(13), pos(bin.000136, 4250)
2018-05-10T10:28:53.987069Z 142 [Note] Start asynchronous binlog_dump to slave (server_id: 13), pos(bin.000136, 4250)
2018-05-10T10:28:53.987233Z 141 [Note] Stop asynchronous binlog_dump to slave (server_id: 13)
2018-05-10T10:29:04.006057Z 143 [Note] While initializing dump thread for slave with UUID <638fd4d4-3eee-11e8-ae18-005056807f1c>, found a zombie dump thread with the same UUID. Master is killing the zombie dump thread(142).
2018-05-10T10:29:04.006173Z 143 [Note] Start binlog_dump to master_thread_id(143) slave_server(13), pos(bin.000136, 4250)
2018-05-10T10:29:04.006192Z 143 [Note] Start asynchronous binlog_dump to slave (server_id: 13), pos(bin.000136, 4250)
2018-05-10T10:29:04.006181Z 142 [Note] Stop asynchronous binlog_dump to slave (server_id: 13)

slave 1:
localhost@root@(none)[2018-05-10 18:15:36]->show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.58.67
                  Master_User: repl
                  Master_Port: 31306
                Connect_Retry: 60
              Master_Log_File: bin.000136
          Read_Master_Log_Pos: 4250
               Relay_Log_File: relay.000314
                Relay_Log_Pos: 570
        Relay_Master_Log_File: bin.000136
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
                   Last_Errno: 0
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 4250
              Relay_Log_Space: 311569
              Until_Condition: None
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
               Last_SQL_Errno: 0
             Master_Server_Id: 11
                  Master_UUID: 3578b000-3eed-11e8-86d5-005056807b31
             Master_Info_File: /data/dmain/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
           Master_Retry_Count: 86400
1 row in set (0.00 sec)

slave 2:
localhost@root@sbtest[2018-05-04 18:38:21]->  show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.58.67
                  Master_User: repl
                  Master_Port: 31306
                Connect_Retry: 60
              Master_Log_File: bin.000136
          Read_Master_Log_Pos: 4250
               Relay_Log_File: relay.000292
                Relay_Log_Pos: 314
        Relay_Master_Log_File: bin.000136
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
                   Last_Errno: 0
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 4250
              Relay_Log_Space: 289038
              Until_Condition: None
                Until_Log_Pos: 0
           Master_SSL_Allowed: No
        Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
                Last_IO_Errno: 0
               Last_SQL_Errno: 0
             Master_Server_Id: 11
                  Master_UUID: 3578b000-3eed-11e8-86d5-005056807b31
             Master_Info_File: /data/dmain/master.info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
           Master_Retry_Count: 86400
1 row in set (0.00 sec)

slave 1:
localhost@root@(none)[2018-05-10 18:20:00]->show global variables where value=10;
+-----------------------------------------------------+-----------+
| Variable_name                                       | Value     |
+-----------------------------------------------------+-----------+
| connect_timeout                                     | 10        |
| innodb_adaptive_flushing_lwm                        | 10        |
| long_query_time                                     | 10.000000 |
| net_retry_count                                     | 10        |
| performance_schema_events_stages_history_size       | 10        |
| performance_schema_events_statements_history_size   | 10        |
| performance_schema_events_transactions_history_size | 10        |
| performance_schema_events_waits_history_size        | 10        |
| performance_schema_max_socket_classes               | 10        |
| performance_schema_max_statement_stack              | 10        |
| protocol_version                                    | 10        |
| slave_net_timeout                                   | 10        |
| slave_transaction_retries                           | 10        |
+-----------------------------------------------------+-----------+
13 rows in set, 212 warnings (0.00 sec)

slave 2:
localhost@root@sbtest[2018-05-04 18:46:13]->show global variables where value=60;
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| net_write_timeout | 60    |
| slave_net_timeout | 60    |
+-------------------+-------+
2 rows in set, 216 warnings (0.01 sec)

so maybe some relation to the variable to slave_net_timeout

How to repeat:
i don't konw

Hi,
I am not sure what are you reporting? If you don't have skip slave start the slave will start automatically as designed?

https://dev.mysql.com/doc/refman/5.7/en/replication-options-slave.html#option_mysqld_skip-...

all best
Bogdan

auto,timed

how to repeat 
1, 1 master as A; 1 semi sync slave as B; 1 async slave as C
2, excute “slave_net_timeout=25;”  on C
3, excute “stop slave;start slave;”  on C
4, monitor A/B/C's log , B and C auto timed excute "start slave;"

variables on A/B/C
show global variables like '%net%timeout%';
A:
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| net_read_timeout  | 30    |
| net_write_timeout | 60    |
| slave_net_timeout | 60    |
+-------------------+-------+
3 rows in set (0.00 sec)

B:
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| net_read_timeout  | 30    |
| net_write_timeout | 60    |
| slave_net_timeout | 60    |
+-------------------+-------+
3 rows in set (0.00 sec)

C:
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| net_read_timeout  | 30    |
| net_write_timeout | 60    |
| slave_net_timeout | 25    |
+-------------------+-------+
3 rows in set (0.00 sec)

attention:the 2nd step ,the value must less than 30.

Hi,

I don't see any bug in this behavior, discussed with my colleagues, not a bug by any mean.

I do have to say that having some slaves be semisync and some slave being async is not recommended setup

all best
Bogdan

B and C auto timed excute "start slave;"
why this behaviour is not a bug？

thank you for your setup advice!