MySQL Bugs: #98075: Multi-Source Replication close a channel causes another replica channel error

Bug #98075	Multi-Source Replication close a channel causes another replica channel error
Submitted:	26 Dec 2019 6:17	Modified:	28 Jan 2020 15:52
Reporter:	Lehman Michael	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.7.25	OS:	CentOS (7.6)
Assigned to:	MySQL Verification Team	CPU Architecture:	Any

Description:
Multi-Source Replication close a channel causes the io thread of another replication channel to close.

I set up a multi-source replication: a->b<->c ,using gtid and semi-replication.

Here b has two replication channels:

Channel_Name: 245
Channel_Name: 248

When I try to close channel '245',error log output on b:

2019-12-26T11:39:44.639973+08:00 48 [Note] Slave SQL thread for channel '245' exiting, replication stopped in log 'mysql-bin.000004' at position 2500
2019-12-26T11:39:44.641331+08:00 47 [Note] Slave I/O thread killed while reading event for channel '245'
2019-12-26T11:39:44.641370+08:00 47 [Note] Slave I/O thread exiting for channel '245', read up to log 'mysql-bin.000004', position 2500
2019-12-26T11:39:56.291698+08:00 49 [ERROR] Slave I/O for channel '248': Replication event checksum verification failed while reading from network. Error_code: 1743
2019-12-26T11:39:56.291802+08:00 49 [ERROR] Slave I/O for channel '248': Relay log write failure: could not queue event from master, Error_code: 1595
2019-12-26T11:39:56.291812+08:00 49 [Note] Slave I/O thread exiting for channel '248', read up to log 'mysql-bin.000004', position 3274

Caused the io thread of channel ’248‘ on b to close.

restart io_thread on channel 248,Operating normally.

How to repeat:
As described

Hi,

Can you please share full config files from all three nodes, I'm having issues reproducing this.

thanks

ok.
	
There are three nodes A,B,C.Both turned on semi-replication and gtid.

root@localhost:(none) 5.7.22-log 06:18:32> show variables like '%gtid%';
+----------------------------------+-----------+
| Variable_name                    | Value     |
+----------------------------------+-----------+
| binlog_gtid_simple_recovery      | ON        |
| enforce_gtid_consistency         | ON        |
| gtid_executed_compression_period | 1000      |
| gtid_mode                        | ON        |
| gtid_next                        | AUTOMATIC |
| gtid_owned                       |           |
| gtid_purged                      |           |
| session_track_gtids              | OFF       |
+----------------------------------+-----------+

root@localhost:(none) 5.7.22-log 06:18:37> show variables like '%semi%';
+-------------------------------------------+------------+
| Variable_name                             | Value      |
+-------------------------------------------+------------+
| rpl_semi_sync_master_enabled              | ON         |
| rpl_semi_sync_master_timeout              | 1000       |
| rpl_semi_sync_master_trace_level          | 32         |
| rpl_semi_sync_master_wait_for_slave_count | 1          |
| rpl_semi_sync_master_wait_no_slave        | ON         |
| rpl_semi_sync_master_wait_point           | AFTER_SYNC |
| rpl_semi_sync_slave_enabled               | ON         |
| rpl_semi_sync_slave_trace_level           | 32         |
+-------------------------------------------+------------+
8 rows in set (0.01 sec)

A->B
B->C
C->B

	
On node B,we have two replication channels:

*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.200.245
                  Master_User: repl
                  Master_Port: 3317
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000005
          Read_Master_Log_Pos: 3693367
               Relay_Log_File: mysql-relay-bin-245.000006
                Relay_Log_Pos: 494
        Relay_Master_Log_File: mysql-bin.000005
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
    ...
          Exec_Master_Log_Pos: 3693367
              Relay_Log_Space: 3694131
    ...
             Master_Server_Id: 2102453317
                  Master_UUID: 8939779c-2631-11ea-accc-52540069b4f2
             Master_Info_File: mysql.slave_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
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 8939779c-2631-11ea-accc-52540069b4f2:12-38,
d3174195-2632-11ea-a253-525400855901:1
            Executed_Gtid_Set: 1fc143bd-2635-11ea-a11b-52540064074e:1-3,
2e1b7dcb-2634-11ea-ae3c-5254006e5e5b:1-3,
8939779c-2631-11ea-accc-52540069b4f2:1-38,
d3174195-2632-11ea-a253-525400855901:1
                Auto_Position: 1
                 Channel_Name: 245
*************************** 2. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 192.168.200.248
                  Master_User: repl
                  Master_Port: 3317
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000006
          Read_Master_Log_Pos: 1375325
               Relay_Log_File: mysql-relay-bin-248.000013
                Relay_Log_Pos: 1375514
        Relay_Master_Log_File: mysql-bin.000006
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
          Exec_Master_Log_Pos: 1375325
              Relay_Log_Space: 1375861
            Master_Server_Id: 2102483317
                  Master_UUID: 1fc143bd-2635-11ea-a11b-52540064074e
             Master_Info_File: mysql.slave_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
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 1fc143bd-2635-11ea-a11b-52540064074e:1-3,
8939779c-2631-11ea-accc-52540069b4f2:8:10-38,
d3174195-2632-11ea-a253-525400855901:1
            Executed_Gtid_Set: 1fc143bd-2635-11ea-a11b-52540064074e:1-3,
2e1b7dcb-2634-11ea-ae3c-5254006e5e5b:1-3,
8939779c-2631-11ea-accc-52540069b4f2:1-38,
d3174195-2632-11ea-a253-525400855901:1
                Auto_Position: 1
         Replicate_Rewrite_DB: 
                 Channel_Name: 248

When I tried to shutdown the channel 245,Then channel 248 iothread was shut down.
root@localhost:(none) 5.7.25-log 06:25:38> stop slave for channel '245';
Query OK, 0 rows affected (0.04 sec)

root@localhost:(none) 5.7.25-log 06:29:53> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: 
                  Master_Host: 192.168.200.245
                  Master_User: repl
                  Master_Port: 3317
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000005
          Read_Master_Log_Pos: 3693367
               Relay_Log_File: mysql-relay-bin-245.000006
                Relay_Log_Pos: 494
        Relay_Master_Log_File: mysql-bin.000005
             Slave_IO_Running: No
            Slave_SQL_Running: No
*************************** 2. row ***************************
               Slave_IO_State: 
                  Master_Host: 192.168.200.248
                  Master_User: repl
                  Master_Port: 3317
                Connect_Retry: 60
              Master_Log_File: mysql-bin.000006
          Read_Master_Log_Pos: 1375325
               Relay_Log_File: mysql-relay-bin-248.000013
                Relay_Log_Pos: 1375514
        Relay_Master_Log_File: mysql-bin.000006
             Slave_IO_Running: No
            Slave_SQL_Running: Yes

On B,replication info is :
root@localhost:mysql 5.7.25-log 06:30:58> select * from slave_master_info\G;
*************************** 1. row ***************************
       Number_of_lines: 25
       Master_log_name: mysql-bin.000005
        Master_log_pos: 3693367
                  Host: 192.168.200.245
             User_name: repl
         User_password: repl
                  Port: 3317
         Connect_retry: 60
           Enabled_ssl: 0
                Ssl_ca: 
            Ssl_capath: 
              Ssl_cert: 
            Ssl_cipher: 
               Ssl_key: 
Ssl_verify_server_cert: 0
             Heartbeat: 30
                  Bind: 
    Ignored_server_ids: 0
                  Uuid: 8939779c-2631-11ea-accc-52540069b4f2
           Retry_count: 86400
               Ssl_crl: 
           Ssl_crlpath: 
 Enabled_auto_position: 1
          Channel_name: 245
           Tls_version: 
*************************** 2. row ***************************
       Number_of_lines: 25
       Master_log_name: mysql-bin.000006
        Master_log_pos: 314
                  Host: 192.168.200.248
             User_name: repl
         User_password: repl
                  Port: 3317
         Connect_retry: 60
           Enabled_ssl: 0
                Ssl_ca: 
            Ssl_capath: 
              Ssl_cert: 
            Ssl_cipher: 
               Ssl_key: 
Ssl_verify_server_cert: 0
             Heartbeat: 30
                  Bind: 
    Ignored_server_ids: 0
                  Uuid: 1fc143bd-2635-11ea-a11b-52540064074e
           Retry_count: 86400
               Ssl_crl: 
           Ssl_crlpath: 
 Enabled_auto_position: 1
          Channel_name: 248
           Tls_version: 
2 rows in set (0.00 sec)

Hi,

I can not reproduce this on 5.7.29, have you tried reproducing this on 5.7.29 ?

thanks