Bug #112030 MySQL 8.0.22 Bug Report: Inconsistent Replication to Multi-Channel Slave (No Err
Submitted: 10 Aug 2023 9:44 Modified: 18 Aug 2023 14:38
Reporter: Krishna Kumar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:8.0.22 OS:Linux (CentOS Linux 7 (Core))
Assigned to: MySQL Verification Team CPU Architecture:Other (3.10.0-1160.62.1.el7.x86_64 #1 SMP Tue Apr 5 16:57:59 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux)

[10 Aug 2023 9:44] Krishna Kumar
Description:
MySQL Version: 8.0.22 [GTID]

Architecture: Master-Master Replication with Multi-Channel Replication and Filtering

Issue Description:
When performing data insertion on the master, the data is being successfully replicated to other slaves and other master except for the multi-channel slave. This results in inconsistency between the master and the multi-channel slave, causing data divergence. No relevant error messages, warnings, or notes are present in the MySQL logs to indicate the cause of the issue. When converting the multi-channel slave's binary logs, the missing data is not present either.

How to repeat:
Steps to Reproduce:

Set up a MySQL architecture with version 8.0.22, utilizing Master-Master replication and Multi-Channel Replication with Filtering.
Create a new table on one of the master nodes.
Populate the new table with a substantial amount of data (e.g., 200 records) on one of the master nodes.
Observe that the data replication occurs successfully on the other slave nodes but not on the multi-channel slave with filtering.

Expected Behavior:
The data inserted into the new table on the master node should replicate consistently across all slave nodes, including the multi-channel slave with filtering.

Actual Behavior:
The data replicates correctly on other slaves except for the multi-channel slave, leading to data inconsistency between the master and the multi-channel slave. Furthermore, when converting the multi-channel slave's binary logs, the missing data is not present in the logs.

Screenshot below for reference

Master1 

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.03 sec)

mysql> call InsertUniqueData1(1,200);
Query OK, 1 row affected (3.25 sec)

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|      200 |
+----------+
1 row in set (0.03 sec)

Slave: [ Data replication successfully]

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.02 sec)

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|      200 |
+----------+
1 row in set (0.00 sec)

Multi channel slave [with filtering]

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|        0 |
+----------+
1 row in set (0.03 sec)

mysql> select count(*) from final_test.example_table1;
+----------+
| count(*) |
+----------+
|      187 |
+----------+
1 row in set (0.01 sec)

--------------------------------------------------------------------------------------PFB for the Master binary log---------------------------------------------------------------------------------------------------------

#230810 12:29:49 server id 208  end_log_pos 26436 CRC32 0x9664188e      GTID    last_committed=80       sequence_number=81      rbr_only=yes    original_committed_timestamp=1691650789332211   immediate_commit_ti
mestamp=1691650789753340     transaction_length=328
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1691650789332211 (2023-08-10 12:29:49.332211 IST)
# immediate_commit_timestamp=1691650789753340 (2023-08-10 12:29:49.753340 IST)
/*!80001 SET @@session.original_commit_timestamp=1691650789332211*//*!*/;
/*!80014 SET @@session.original_server_version=80022*//*!*/;
/*!80014 SET @@session.immediate_server_version=80022*//*!*/;
SET @@SESSION.GTID_NEXT= '30c8c31f-05e4-11ee-b783-705a0f4ea406:2096'/*!*/;
# at 26436
#230810 12:29:49 server id 208  end_log_pos 26517 CRC32 0x845cee21      Query   thread_id=11    exec_time=0     error_code=0
SET TIMESTAMP=1691650789/*!*/;
BEGIN
/*!*/;
# at 26517
#230810 12:29:49 server id 208  end_log_pos 26591 CRC32 0xd11d50e9      Table_map: `final_test`.`example_table` mapped to number 83
# at 26591
#230810 12:29:49 server id 208  end_log_pos 26647 CRC32 0x216b7c8c      Write_rows: table id 83 flags: STMT_END_F
### INSERT INTO `final_test`.`example_table`
### SET
###   @1=159 /* INT meta=0 nullable=0 is_null=0 */
###   @2='CommonName' /* VARSTRING(1020) meta=1020 nullable=0 is_null=0 */
###   @3=80 /* INT meta=0 nullable=0 is_null=0 */
# at 26647
#230810 12:29:49 server id 208  end_log_pos 26678 CRC32 0x1efe79b9      Xid = 206
COMMIT/*!*/;
# at 26678
#230810 12:29:49 server id 208  end_log_pos 26764 CRC32 0xb68d7898      GTID    last_committed=81       sequence_number=82      rbr_only=yes    original_committed_timestamp=1691650789342592   immediate_commit_timestamp=1691650789772297     transaction_length=328
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1691650789342592 (2023-08-10 12:29:49.342592 IST)
# immediate_commit_timestamp=1691650789772297 (2023-08-10 12:29:49.772297 IST)
/*!80001 SET @@session.original_commit_timestamp=1691650789342592*//*!*/;
/*!80014 SET @@session.original_server_version=80022*//*!*/;
/*!80014 SET @@session.immediate_server_version=80022*//*!*/;
SET @@SESSION.GTID_NEXT= '30c8c31f-05e4-11ee-b783-705a0f4ea406:2097'/*!*/;
# at 26764
#230810 12:29:49 server id 208  end_log_pos 26845 CRC32 0xb29e03ce      Query   thread_id=11    exec_time=0     error_code=0
SET TIMESTAMP=1691650789/*!*/;
BEGIN
/*!*/;
# at 26845
#230810 12:29:49 server id 208  end_log_pos 26919 CRC32 0x388ad90e      Table_map: `final_test`.`example_table` mapped to number 83
# at 26919
#230810 12:29:49 server id 208  end_log_pos 26975 CRC32 0x209cbd91      Write_rows: table id 83 flags: STMT_END_F
### INSERT INTO `final_test`.`example_table`
### SET
###   @1=161 /* INT meta=0 nullable=0 is_null=0 */
###   @2='CommonName' /* VARSTRING(1020) meta=1020 nullable=0 is_null=0 */
###   @3=81 /* INT meta=0 nullable=0 is_null=0 */
# at 26975
#230810 12:29:49 server id 208  end_log_pos 27006 CRC32 0xd8b96ae2      Xid = 208
COMMIT/*!*/;

--------------------------------------------------------------------------------------PFB for the slave's binary log---------------------------------------------------------------------------------------------------------

#230810 12:33:13 server id 208  end_log_pos 94135 CRC32 0x7e91088d      GTID    last_committed=282      sequence_number=283     rbr_only=yes    original_committed_timestamp=1691650993700838   immediate_commit_ti
mestamp=1691650993936428     transaction_length=333
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1691650993700838 (2023-08-10 12:33:13.700838 IST)
# immediate_commit_timestamp=1691650993936428 (2023-08-10 12:33:13.936428 IST)
/*!80001 SET @@session.original_commit_timestamp=1691650993700838*//*!*/;
/*!80014 SET @@session.original_server_version=80022*//*!*/;
/*!80014 SET @@session.immediate_server_version=80033*//*!*/;
SET @@SESSION.GTID_NEXT= '30c8c31f-05e4-11ee-b783-705a0f4ea406:2298'/*!*/;
# at 94135
#230810 12:33:13 server id 208  end_log_pos 94216 CRC32 0xc25f2c8c      Query   thread_id=11    exec_time=0     error_code=0
SET TIMESTAMP=1691650993/*!*/;
BEGIN
/*!*/;
# at 94216
#230810 12:33:13 server id 208  end_log_pos 94291 CRC32 0x276b7b77      Table_map: `final_test`.`example_table1` mapped to number 91
# at 94291
#230810 12:33:13 server id 208  end_log_pos 94347 CRC32 0x77bce91f      Write_rows: table id 91 flags: STMT_END_F
### INSERT INTO `final_test`.`example_table1`
### SET
###   @1=159 /* INT meta=0 nullable=0 is_null=0 */
###   @2='CommonName' /* VARSTRING(1020) meta=1020 nullable=0 is_null=0 */
###   @3=80 /* INT meta=0 nullable=0 is_null=0 */
# at 94347
#230810 12:33:13 server id 208  end_log_pos 94378 CRC32 0x25792f48      Xid = 1137
COMMIT/*!*/;
# at 94378
#230810 12:33:13 server id 208  end_log_pos 94466 CRC32 0x0a643344      GTID    last_committed=283      sequence_number=284     rbr_only=no     original_committed_timestamp=1691650993724692   immediate_commit_timestamp=1691650993957439     transaction_length=231
# original_commit_timestamp=1691650993724692 (2023-08-10 12:33:13.724692 IST)
# immediate_commit_timestamp=1691650993957439 (2023-08-10 12:33:13.957439 IST)
/*!80001 SET @@session.original_commit_timestamp=1691650993724692*//*!*/;
/*!80014 SET @@session.original_server_version=80022*//*!*/;
/*!80014 SET @@session.immediate_server_version=80033*//*!*/;
SET @@SESSION.GTID_NEXT= '30c8c31f-05e4-11ee-b783-705a0f4ea406:2299'/*!*/;
# at 94466
#230810 12:33:13 server id 208  end_log_pos 94537 CRC32 0xcfd76b1e      Query   thread_id=24    exec_time=0     error_code=0
SET TIMESTAMP=1691650993/*!*/;
BEGIN
/*!*/;
[10 Aug 2023 14:17] MySQL Verification Team
Hi,

8.0.22 is rather old, I tested this with 8.0.34 and I cannot reproduce the issue using the procedure you described. Have you tried reproducing this with 8.0.34 or 8.1.0?

Thank you for using MySQL
[14 Aug 2023 8:54] Krishna Kumar
Yes, we attempted to resolve the issue by testing versions 8.0.34 and 8.1.0. However, the problem of data mismatch between the master and the multi-channel slave persists.
[14 Aug 2023 10:59] MySQL Verification Team
I am not able to reproduce this on 8.0.34. Can you make a reproducible test case?
[18 Aug 2023 4:04] Krishna Kumar
We have tested the same with 8.0.34 version and the data got replicated without any issues. Thanks.
[18 Aug 2023 14:38] MySQL Verification Team
great, I'm closing the bug.

Thank you for confirmation