Bug #93779 | dml in table with trigger to other Table map in binlog lead to slave sql stopped | ||
---|---|---|---|
Submitted: | 2 Jan 2019 9:18 | Modified: | 30 Jan 2019 14:07 |
Reporter: | mohamed atef | Email Updates: | |
Status: | Verified | Impact on me: | |
Category: | MySQL Server: Replication | Severity: | S1 (Critical) |
Version: | 5.7.24 | OS: | Windows |
Assigned to: | CPU Architecture: | Any | |
Tags: | dml in table with trigger to other Table map |
[2 Jan 2019 9:18]
mohamed atef
[9 Jan 2019 9:42]
mohamed atef
no response ????
[17 Jan 2019 16:15]
MySQL Verification Team
Hi, I do not see a problem here master [localhost] {msandbox} (ABC) > show variables like 'binlog_format'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | binlog_format | ROW | +---------------+-------+ 1 row in set (0.01 sec) master [localhost] {msandbox} (ABC) > master [localhost] {msandbox} (ABC) > SHOW BINLOG EVENTS; | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | mysql-bin.000001 | 4 | Format_desc | 1 | 123 | Server ver: 5.7.24-log, Binlog ver: 4 ... | mysql-bin.000001 | 6157 | Anonymous_Gtid | 1 | 6222 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | mysql-bin.000001 | 6222 | Query | 1 | 6295 | BEGIN | mysql-bin.000001 | 6295 | Table_map | 1 | 6344 | table_id: 120 (ABC.tb1) | mysql-bin.000001 | 6344 | Table_map | 1 | 6393 | table_id: 119 (ABC.tb2) | mysql-bin.000001 | 6393 | Write_rows | 1 | 6446 | table_id: 120 flags: STMT_END_F | mysql-bin.000001 | 6446 | Xid | 1 | 6477 | COMMIT /* xid=112 */ | mysql-bin.000001 | 6477 | Anonymous_Gtid | 1 | 6542 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | mysql-bin.000001 | 6542 | Query | 1 | 6615 | BEGIN | mysql-bin.000001 | 6615 | Table_map | 1 | 6664 | table_id: 120 (ABC.tb1) | mysql-bin.000001 | 6664 | Table_map | 1 | 6713 | table_id: 119 (ABC.tb2) | mysql-bin.000001 | 6713 | Write_rows | 1 | 6764 | table_id: 120 | mysql-bin.000001 | 6764 | Write_rows | 1 | 6823 | table_id: 119 flags: STMT_END_F | mysql-bin.000001 | 6823 | Xid | 1 | 6854 | COMMIT /* xid=114 */ +------------------+------+----------------+-----------+-------------+---------------------- 63 rows in set (0.00 sec) master [localhost] {msandbox} (ABC) > select * from tb2; +----+-----+-------+ | ID | DID | DT | +----+-----+-------+ | 2 | 2 | AHMED | +----+-----+-------+ 1 row in set (0.00 sec)
[17 Jan 2019 16:16]
MySQL Verification Team
and on the second box slave2 [localhost] {msandbox} ((none)) > select * from ABC.tb1; +----+---------+----+ | ID | DT | lg | +----+---------+----+ | 1 | MOHAMED | 0 | | 2 | AHMED | 1 | +----+---------+----+ 2 rows in set (0.00 sec) slave2 [localhost] {msandbox} ((none)) > select * from ABC.tb2; +----+-----+-------+ | ID | DID | DT | +----+-----+-------+ | 2 | 2 | AHMED | +----+-----+-------+ 1 row in set (0.00 sec) slave2 [localhost] {msandbox} ((none)) > show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 127.0.0.1 Master_User: rsandbox Master_Port: 21599 Connect_Retry: 60 Master_Log_File: mysql-bin.000001 Read_Master_Log_Pos: 6854 Relay_Log_File: mysql-relay.000002 Relay_Log_Pos: 7067 Relay_Master_Log_File: mysql-bin.000001 Slave_IO_Running: Yes 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: 6854 Relay_Log_Space: 7270 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: 0 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_UUID: 00021599-1111-1111-1111-111111111111 Master_Info_File: /home/arhimed/sandboxes/rsandbox_mysql-5_7_24/node2/data/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: Executed_Gtid_Set: Auto_Position: 0 Replicate_Rewrite_DB: Channel_Name: Master_TLS_Version: 1 row in set (0.00 sec) slave2 [localhost] {msandbox} ((none)) >
[17 Jan 2019 23:47]
mohamed atef
hi look i have 2 servers with master to master replication in both servers i have 2 tables tb1 and tb2 in first server when i insert row in tb1 and the column3 (tinyint(1)) value is 1 the after trigger in tb1 will insert row in tb2 and binlog event show that table map for tb1 and tb2 write rows for tb1 and tb2 but if i insert row in tb1 and the value of column3 is 0 the trigger will not insert row in tb2 binlog event show table map for tb1 and tb2 write rows for tb1 only <===== when the second server will execute write the first event normally it check the column count and data type in tb2 because the event contain write rows in tb2 so it must check the table tb2 before write the event but when the slave will execute write the second event why ?????? it check the column count and data type in tb2 while the event didn`t contain write rows in tb2 only binlog show table map for tb2 this make salve sql error if in the second server we change the data type of any column before it get this events from the first server because the server will check column count and data type in tb2 and it will not be the same so why binlog event in the second event show table map for tb2 and why the server check column count and data type in tb2 while no need to write any rows in this table
[18 Jan 2019 7:26]
MySQL Verification Team
Hi, Something does not add up here. Can you give me SHOW BINLOG EVENTS; from both servers after INSERT INTO `ABC`.`tb1` (`ID`, `DT`, `lg`) VALUES ('1', 'MOHAMED', '0'); (this is the one not adding row to tb2 that you say makes a problem for you) Thanks
[18 Jan 2019 8:49]
mohamed atef
look again i have server1 ip 192.168.1.100 server2 ip 192.168.1.101 in server1 stop slave; reset slave all; change master to master_host='192.168.1.101',master_port=3306,master_user='syncuser',master_password='123456',master_auto_position=1 for channel 'm1'; start slave; in server2 stop slave; reset slave all; change master to master_host='192.168.1.100',master_port=3306,master_user='syncuser',master_password='123456',master_auto_position=1 for channel 'm2'; start slave; in both server con file replicate-do-db = abc1 binlog-do-db = abc1 now in server1 we will run this create database abc1 charset utf8 collate utf8_unicode_ci; use abc1; CREATE TABLE `tb1` ( `ID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, `lg` tinyint(1) unsigned NOT NULL DEFAULT '0', PRIMARY KEY (`ID`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci; use abc1; DROP TRIGGER IF EXISTS `abc1`.`tb1_AFTER_INSERT`; DELIMITER $$ USE `abc1`$$ CREATE DEFINER=`root`@`%` TRIGGER `abc1`.`tb1_AFTER_INSERT` AFTER INSERT ON `tb1` FOR EACH ROW BEGIN if new.lg=1 then insert into tb2 (ID,DID,DT) VALUES (NEW.ID,NEW.ID,NEW.DT); end if; END$$ DELIMITER ; use abc1; CREATE TABLE `tb2` ( `ID` bigint(20) unsigned NOT NULL, `DID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, PRIMARY KEY (`ID`), KEY `IDX` (`DID`) USING BTREE, CONSTRAINT `IDXFK` FOREIGN KEY (`DID`) REFERENCES `tb1` (`ID`) ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci; ##### in server1 then will will insert in tb1 INSERT INTO `tb1` (`ID`,`DT`,`lg`) VALUES (1,'mohamed',1); then trigger will insert into tb2 the recocord and it will replicated to server2 now will simulate that the connection bewtween the two server is down so we will execute in both servers stop slave; then in server1 we will insert this INSERT INTO `tb1` (`ID`,`DT`,`lg`) VALUES (2,'ahmed',0); this the trigger will not insert record to tb2; then in server2 we will execute this ddl statement use abc1; alter TABLE `tb2` change column DT `DT` varchar(45) COLLATE utf8_unicode_ci NOT NULL; then we will execute start slave; in both servers then in server2 show slave status show this { "Slave_IO_State" : "Waiting for master to send event", "Master_Host" : "192.168.245.102", "Master_User" : "syncuser", "Master_Port" : 3306, "Connect_Retry" : 60, "Master_Log_File" : "abc-bin.000001", "Read_Master_Log_Pos" : 2656, "Relay_Log_File" : "abc-relay-m2.000003", "Relay_Log_Pos" : 448, "Relay_Master_Log_File" : "abc-bin.000001", "Slave_IO_Running" : "Yes", "Slave_SQL_Running" : "No", "Replicate_Do_DB" : "abc1", "Replicate_Ignore_DB" : "", "Replicate_Do_Table" : "", "Replicate_Ignore_Table" : "", "Replicate_Wild_Do_Table" : "", "Replicate_Wild_Ignore_Table" : "", "Last_Errno" : 1677, "Last_Error" : "Column 2 of table 'abc1.tb2' cannot be converted from type 'varchar(150(bytes))' to type 'varchar(135(bytes) utf8)'", "Skip_Counter" : 0, "Exec_Master_Log_Pos" : 2112, "Relay_Log_Space" : 3185, "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" : 1677, "Last_SQL_Error" : "Column 2 of table 'abc1.tb2' cannot be converted from type 'varchar(150(bytes))' to type 'varchar(135(bytes) utf8)'", "Replicate_Ignore_Server_Ids" : "", "Master_Server_Id" : 100, "Master_UUID" : "a3ec7103-4809-11e8-8994-521584a32842", "Master_Info_File" : "mysql.slave_master_info", "SQL_Delay" : 0, "SQL_Remaining_Delay" : null, "Slave_SQL_Running_State" : "", "Master_Retry_Count" : 86400, "Master_Bind" : "", "Last_IO_Error_Timestamp" : "", "Last_SQL_Error_Timestamp" : "190118 11:21:38", "Master_SSL_Crl" : "", "Master_SSL_Crlpath" : "", "Retrieved_Gtid_Set" : "a3ec7103-4809-11e8-8994-521584a32842:1-7", "Executed_Gtid_Set" : "a3ec7103-4809-11e8-8994-521584a32842:1-6,\neca0e7c5-6b40-11e7-9267-18dbf2334ed5:1", "Auto_Position" : 1, "Replicate_Rewrite_DB" : "", "Channel_Name" : "m2", "Master_TLS_Version" : "" } the slave stop working because column2 changed from varchar(50) to varchar(45) why the slave check tb2 before execute the insert event in tb1 while no insert for tb2
[18 Jan 2019 8:50]
mohamed atef
this is binlog event from server1 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #190118 11:18:56 server id 100 end_log_pos 123 CRC32 0x99da9713 Start: binlog v 4, server v 5.7.23-log created 190118 11:18:56 at startup # Warning: this binlog is either in use or was not closed properly. ROLLBACK/*!*/; # at 123 #190118 11:18:56 server id 100 end_log_pos 154 CRC32 0xae8c9f2a Previous-GTIDs # [empty] # at 154 #190118 11:19:17 server id 100 end_log_pos 219 CRC32 0xa489d996 GTID last_committed=0 sequence_number=1 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:1'/*!*/; # at 219 #190118 11:19:17 server id 100 end_log_pos 350 CRC32 0x9bbc12f4 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799557/*!*/; SET @@session.pseudo_thread_id=4/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1344274432/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=192/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; create database abc1 charset utf8 collate utf8_unicode_ci /*!*/; # at 350 #190118 11:19:17 server id 100 end_log_pos 415 CRC32 0x42bf42eb GTID last_committed=1 sequence_number=2 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:2'/*!*/; # at 415 #190118 11:19:17 server id 100 end_log_pos 730 CRC32 0x9937fedd Query thread_id=4 exec_time=1 error_code=0 use `abc1`/*!*/; SET TIMESTAMP=1547799557/*!*/; CREATE TABLE `tb1` ( `ID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, `lg` tinyint(1) unsigned NOT NULL DEFAULT '0', PRIMARY KEY (`ID`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci /*!*/; # at 730 #190118 11:19:18 server id 100 end_log_pos 795 CRC32 0x793012e0 GTID last_committed=2 sequence_number=3 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:3'/*!*/; # at 795 #190118 11:19:18 server id 100 end_log_pos 910 CRC32 0xb95e3aa9 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799558/*!*/; DROP TRIGGER IF EXISTS `abc1`.`tb1_AFTER_INSERT` /*!*/; # at 910 #190118 11:19:19 server id 100 end_log_pos 975 CRC32 0x40bd4c16 GTID last_committed=3 sequence_number=4 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:4'/*!*/; # at 975 #190118 11:19:19 server id 100 end_log_pos 1243 CRC32 0x8aaf1837 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799559.079155/*!*/; CREATE DEFINER=`root`@`%` TRIGGER `abc1`.`tb1_AFTER_INSERT` AFTER INSERT ON `tb1` FOR EACH ROW BEGIN if new.lg=1 then insert into tb2 (ID,DID,DT) VALUES (NEW.ID,NEW.ID,NEW.DT); end if; END /*!*/; # at 1243 #190118 11:19:19 server id 100 end_log_pos 1308 CRC32 0xe6aae811 GTID last_committed=4 sequence_number=5 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:5'/*!*/; # at 1308 #190118 11:19:19 server id 100 end_log_pos 1729 CRC32 0x2ef9dcdc Query thread_id=4 exec_time=1 error_code=0 SET TIMESTAMP=1547799559/*!*/; CREATE TABLE `tb2` ( `ID` bigint(20) unsigned NOT NULL, `DID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, PRIMARY KEY (`ID`), KEY `IDX` (`DID`) USING BTREE, CONSTRAINT `IDXFK` FOREIGN KEY (`DID`) REFERENCES `tb1` (`ID`) ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci /*!*/; # at 1729 #190118 11:20:07 server id 100 end_log_pos 1794 CRC32 0x5e8dc862 GTID last_committed=5 sequence_number=6 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:6'/*!*/; # at 1794 #190118 11:20:07 server id 100 end_log_pos 1868 CRC32 0x1d62f976 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799607/*!*/; BEGIN /*!*/; # at 1868 #190118 11:20:07 server id 100 end_log_pos 1918 CRC32 0x5f37e3c1 Table_map: `abc1`.`tb1` mapped to number 111 # at 1918 #190118 11:20:07 server id 100 end_log_pos 1968 CRC32 0x2bff0e2e Table_map: `abc1`.`tb2` mapped to number 112 # at 1968 #190118 11:20:07 server id 100 end_log_pos 2021 CRC32 0x3c5c3190 Write_rows: table id 111 # at 2021 #190118 11:20:07 server id 100 end_log_pos 2081 CRC32 0xf0c1b0d1 Write_rows: table id 112 flags: STMT_END_F ### INSERT INTO `abc1`.`tb1` ### SET ### @1=1 ### @2='mohamed' ### @3=1 ### INSERT INTO `abc1`.`tb2` ### SET ### @1=1 ### @2=1 ### @3='mohamed' # at 2081 #190118 11:20:07 server id 100 end_log_pos 2112 CRC32 0x08b47a64 Xid = 144 COMMIT/*!*/; # at 2112 #190118 11:21:17 server id 100 end_log_pos 2177 CRC32 0xb3446031 GTID last_committed=6 sequence_number=7 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:7'/*!*/; # at 2177 #190118 11:21:17 server id 100 end_log_pos 2251 CRC32 0x2828cf4e Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799677/*!*/; BEGIN /*!*/; # at 2251 #190118 11:21:17 server id 100 end_log_pos 2301 CRC32 0xb8941bef Table_map: `abc1`.`tb1` mapped to number 111 # at 2301 #190118 11:21:17 server id 100 end_log_pos 2351 CRC32 0x5362320d Table_map: `abc1`.`tb2` mapped to number 112 # at 2351 #190118 11:21:17 server id 100 end_log_pos 2402 CRC32 0xded5406b Write_rows: table id 111 flags: STMT_END_F ### INSERT INTO `abc1`.`tb1` ### SET ### @1=2 ### @2='ahmed' ### @3=0 # at 2402 #190118 11:21:17 server id 100 end_log_pos 2433 CRC32 0x23d35e2c Xid = 170 COMMIT/*!*/;
[18 Jan 2019 8:50]
mohamed atef
and this the relay log event in server2 in 2 files file 1 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #190118 11:18:08 server id 1000 end_log_pos 123 CRC32 0x338c07f6 Start: binlog v 4, server v 5.7.24-log created 190118 11:18:08 # This Format_description_event appears in a relay log and was generated by the slave thread. # at 123 #190118 11:18:08 server id 1000 end_log_pos 154 CRC32 0x03ba1359 Previous-GTIDs # [empty] # at 154 #700101 3:00:00 server id 100 end_log_pos 0 CRC32 0x0410a8be Rotate to abc-bin.000001 pos: 4 # at 199 #190118 11:18:56 server id 100 end_log_pos 123 CRC32 0x99da9713 Start: binlog v 4, server v 5.7.23-log created 190118 11:18:56 at startup ROLLBACK/*!*/; # at 318 #190118 11:18:08 server id 0 end_log_pos 363 CRC32 0x0de3b1af Rotate to abc-bin.000001 pos: 154 # at 363 #190118 11:19:17 server id 100 end_log_pos 219 CRC32 0xa489d996 GTID last_committed=0 sequence_number=1 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:1'/*!*/; # at 428 #190118 11:19:17 server id 100 end_log_pos 350 CRC32 0x9bbc12f4 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799557/*!*/; SET @@session.pseudo_thread_id=4/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1344274432/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=192/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; create database abc1 charset utf8 collate utf8_unicode_ci /*!*/; # at 559 #190118 11:19:17 server id 100 end_log_pos 415 CRC32 0x42bf42eb GTID last_committed=1 sequence_number=2 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:2'/*!*/; # at 624 #190118 11:19:17 server id 100 end_log_pos 730 CRC32 0x9937fedd Query thread_id=4 exec_time=1 error_code=0 use `abc1`/*!*/; SET TIMESTAMP=1547799557/*!*/; CREATE TABLE `tb1` ( `ID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, `lg` tinyint(1) unsigned NOT NULL DEFAULT '0', PRIMARY KEY (`ID`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci /*!*/; # at 939 #190118 11:19:18 server id 100 end_log_pos 795 CRC32 0x793012e0 GTID last_committed=2 sequence_number=3 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:3'/*!*/; # at 1004 #190118 11:19:18 server id 100 end_log_pos 910 CRC32 0xb95e3aa9 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799558/*!*/; DROP TRIGGER IF EXISTS `abc1`.`tb1_AFTER_INSERT` /*!*/; # at 1119 #190118 11:19:19 server id 100 end_log_pos 975 CRC32 0x40bd4c16 GTID last_committed=3 sequence_number=4 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:4'/*!*/; # at 1184 #190118 11:19:19 server id 100 end_log_pos 1243 CRC32 0x8aaf1837 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799559.079155/*!*/; CREATE DEFINER=`root`@`%` TRIGGER `abc1`.`tb1_AFTER_INSERT` AFTER INSERT ON `tb1` FOR EACH ROW BEGIN if new.lg=1 then insert into tb2 (ID,DID,DT) VALUES (NEW.ID,NEW.ID,NEW.DT); end if; END /*!*/; # at 1452 #190118 11:19:19 server id 100 end_log_pos 1308 CRC32 0xe6aae811 GTID last_committed=4 sequence_number=5 rbr_only=no SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:5'/*!*/; # at 1517 #190118 11:19:19 server id 100 end_log_pos 1729 CRC32 0x2ef9dcdc Query thread_id=4 exec_time=1 error_code=0 SET TIMESTAMP=1547799559/*!*/; CREATE TABLE `tb2` ( `ID` bigint(20) unsigned NOT NULL, `DID` bigint(20) unsigned NOT NULL, `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL, PRIMARY KEY (`ID`), KEY `IDX` (`DID`) USING BTREE, CONSTRAINT `IDXFK` FOREIGN KEY (`DID`) REFERENCES `tb1` (`ID`) ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci /*!*/; # at 1938 #190118 11:20:07 server id 100 end_log_pos 1794 CRC32 0x5e8dc862 GTID last_committed=5 sequence_number=6 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:6'/*!*/; # at 2003 #190118 11:20:07 server id 100 end_log_pos 1868 CRC32 0x1d62f976 Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799607/*!*/; BEGIN /*!*/; # at 2077 #190118 11:20:07 server id 100 end_log_pos 1918 CRC32 0x5f37e3c1 Table_map: `abc1`.`tb1` mapped to number 111 # at 2127 #190118 11:20:07 server id 100 end_log_pos 1968 CRC32 0x2bff0e2e Table_map: `abc1`.`tb2` mapped to number 112 # at 2177 #190118 11:20:07 server id 100 end_log_pos 2021 CRC32 0x3c5c3190 Write_rows: table id 111 # at 2230 #190118 11:20:07 server id 100 end_log_pos 2081 CRC32 0xf0c1b0d1 Write_rows: table id 112 flags: STMT_END_F ### INSERT INTO `abc1`.`tb1` ### SET ### @1=1 ### @2='mohamed' ### @3=1 ### INSERT INTO `abc1`.`tb2` ### SET ### @1=1 ### @2=1 ### @3='mohamed' # at 2290 #190118 11:20:07 server id 100 end_log_pos 2112 CRC32 0x08b47a64 Xid = 144 COMMIT/*!*/; # at 2321 #190118 11:21:37 server id 1000 end_log_pos 2371 CRC32 0x93e469e7 Rotate to abc-relay-m2.000003 pos: 4 SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; DELIMITER ; # End of log file /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
[18 Jan 2019 8:51]
mohamed atef
relay log files in server2 file 2 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #190118 11:21:37 server id 1000 end_log_pos 123 CRC32 0x242604a2 Start: binlog v 4, server v 5.7.24-log created 190118 11:21:37 # This Format_description_event appears in a relay log and was generated by the slave thread. # at 123 #190118 11:21:37 server id 1000 end_log_pos 194 CRC32 0x14db803f Previous-GTIDs # a3ec7103-4809-11e8-8994-521584a32842:1-6 # at 194 #700101 3:00:00 server id 100 end_log_pos 0 CRC32 0x0410a8be Rotate to abc-bin.000001 pos: 4 # at 239 #190118 11:18:56 server id 100 end_log_pos 123 CRC32 0xa7cf0a20 Start: binlog v 4, server v 5.7.23-log created 190118 11:18:56 # at 358 #190118 11:21:37 server id 0 end_log_pos 403 CRC32 0x62435f38 Rotate to abc-bin.000001 pos: 154 # at 403 #190118 11:21:37 server id 0 end_log_pos 448 CRC32 0x88080030 Rotate to abc-bin.000001 pos: 2112 # at 448 #190118 11:21:17 server id 100 end_log_pos 2177 CRC32 0xb3446031 GTID last_committed=6 sequence_number=7 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:7'/*!*/; # at 513 #190118 11:21:17 server id 100 end_log_pos 2251 CRC32 0x2828cf4e Query thread_id=4 exec_time=0 error_code=0 SET TIMESTAMP=1547799677/*!*/; SET @@session.pseudo_thread_id=4/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1344274432/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=192/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; BEGIN /*!*/; # at 587 #190118 11:21:17 server id 100 end_log_pos 2301 CRC32 0xb8941bef Table_map: `abc1`.`tb1` mapped to number 111 # at 637 #190118 11:21:17 server id 100 end_log_pos 2351 CRC32 0x5362320d Table_map: `abc1`.`tb2` mapped to number 112 # at 687 #190118 11:21:17 server id 100 end_log_pos 2402 CRC32 0xded5406b Write_rows: table id 111 flags: STMT_END_F ### INSERT INTO `abc1`.`tb1` ### SET ### @1=2 ### @2='ahmed' ### @3=0 # at 738 #190118 11:21:17 server id 100 end_log_pos 2433 CRC32 0x23d35e2c Xid = 170 COMMIT/*!*/; # at 769 #190118 11:21:37 server id 0 end_log_pos 814 CRC32 0xb06629ca Rotate to abc-bin.000001 pos: 2656 SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; DELIMITER ; # End of log file /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/; in file 2 you will find that ther server 2 will execute only insert in tb1 but why it check columns in tb2 although there is no write event in this table
[18 Jan 2019 8:52]
mohamed atef
show binlog events in server1 [ { "Log_name" : "abc-bin.000001", "Pos" : 4, "Event_type" : "Format_desc", "Server_id" : 100, "End_log_pos" : 123, "Info" : "Server ver: 5.7.23-log, Binlog ver: 4" }, { "Log_name" : "abc-bin.000001", "Pos" : 123, "Event_type" : "Previous_gtids", "Server_id" : 100, "End_log_pos" : 154, "Info" : "" }, { "Log_name" : "abc-bin.000001", "Pos" : 154, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 219, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:1'" }, { "Log_name" : "abc-bin.000001", "Pos" : 219, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 350, "Info" : "create database abc1 charset utf8 collate utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 350, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 415, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:2'" }, { "Log_name" : "abc-bin.000001", "Pos" : 415, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 730, "Info" : "use `abc1`; CREATE TABLE `tb1` (\n `ID` bigint(20) unsigned NOT NULL,\n `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL,\n `lg` tinyint(1) unsigned NOT NULL DEFAULT '0',\n PRIMARY KEY (`ID`)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 730, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 795, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:3'" }, { "Log_name" : "abc-bin.000001", "Pos" : 795, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 910, "Info" : "use `abc1`; DROP TRIGGER IF EXISTS `abc1`.`tb1_AFTER_INSERT`" }, { "Log_name" : "abc-bin.000001", "Pos" : 910, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 975, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:4'" }, { "Log_name" : "abc-bin.000001", "Pos" : 975, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1243, "Info" : "use `abc1`; CREATE DEFINER=`root`@`%` TRIGGER `abc1`.`tb1_AFTER_INSERT` AFTER INSERT ON `tb1` FOR EACH ROW\nBEGIN\n\nif new.lg=1 then \ninsert into tb2 (ID,DID,DT) VALUES (NEW.ID,NEW.ID,NEW.DT);\nend if;\nEND" }, { "Log_name" : "abc-bin.000001", "Pos" : 1243, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 1308, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:5'" }, { "Log_name" : "abc-bin.000001", "Pos" : 1308, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1729, "Info" : "use `abc1`; CREATE TABLE `tb2` (\n `ID` bigint(20) unsigned NOT NULL,\n `DID` bigint(20) unsigned NOT NULL,\n `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL,\n PRIMARY KEY (`ID`),\n KEY `IDX` (`DID`) USING BTREE,\n CONSTRAINT `IDXFK` FOREIGN KEY (`DID`) REFERENCES `tb1` (`ID`) ON UPDATE CASCADE\n) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 1729, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 1794, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:6'" }, { "Log_name" : "abc-bin.000001", "Pos" : 1794, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1868, "Info" : "BEGIN" }, { "Log_name" : "abc-bin.000001", "Pos" : 1868, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 1918, "Info" : "table_id: 111 (abc1.tb1)" }, { "Log_name" : "abc-bin.000001", "Pos" : 1918, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 1968, "Info" : "table_id: 112 (abc1.tb2)" }, { "Log_name" : "abc-bin.000001", "Pos" : 1968, "Event_type" : "Write_rows", "Server_id" : 100, "End_log_pos" : 2021, "Info" : "table_id: 111" }, { "Log_name" : "abc-bin.000001", "Pos" : 2021, "Event_type" : "Write_rows", "Server_id" : 100, "End_log_pos" : 2081, "Info" : "table_id: 112 flags: STMT_END_F" }, { "Log_name" : "abc-bin.000001", "Pos" : 2081, "Event_type" : "Xid", "Server_id" : 100, "End_log_pos" : 2112, "Info" : "COMMIT /* xid=144 */" }, { "Log_name" : "abc-bin.000001", "Pos" : 2112, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 2177, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:7'" }, { "Log_name" : "abc-bin.000001", "Pos" : 2177, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 2251, "Info" : "BEGIN" }, { "Log_name" : "abc-bin.000001", "Pos" : 2251, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 2301, "Info" : "table_id: 111 (abc1.tb1)" }, { "Log_name" : "abc-bin.000001", "Pos" : 2301, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 2351, "Info" : "table_id: 112 (abc1.tb2)" }, { "Log_name" : "abc-bin.000001", "Pos" : 2351, "Event_type" : "Write_rows", "Server_id" : 100, "End_log_pos" : 2402, "Info" : "table_id: 111 flags: STMT_END_F" }, { "Log_name" : "abc-bin.000001", "Pos" : 2402, "Event_type" : "Xid", "Server_id" : 100, "End_log_pos" : 2433, "Info" : "COMMIT /* xid=170 */" }, { "Log_name" : "abc-bin.000001", "Pos" : 2433, "Event_type" : "Gtid", "Server_id" : 1000, "End_log_pos" : 2498, "Info" : "SET @@SESSION.GTID_NEXT= 'eca0e7c5-6b40-11e7-9267-18dbf2334ed5:1'" }, { "Log_name" : "abc-bin.000001", "Pos" : 2498, "Event_type" : "Query", "Server_id" : 1000, "End_log_pos" : 2656, "Info" : "use `abc1`; alter TABLE `tb2` change column DT `DT` varchar(45) COLLATE utf8_unicode_ci NOT NULL" } ]
[18 Jan 2019 8:53]
mohamed atef
shw binlog events in server2 [ { "Log_name" : "abc-bin.000001", "Pos" : 4, "Event_type" : "Format_desc", "Server_id" : 1000, "End_log_pos" : 123, "Info" : "Server ver: 5.7.24-log, Binlog ver: 4" }, { "Log_name" : "abc-bin.000001", "Pos" : 123, "Event_type" : "Previous_gtids", "Server_id" : 1000, "End_log_pos" : 154, "Info" : "" }, { "Log_name" : "abc-bin.000001", "Pos" : 154, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 219, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:1'" }, { "Log_name" : "abc-bin.000001", "Pos" : 219, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 350, "Info" : "create database abc1 charset utf8 collate utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 350, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 415, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:2'" }, { "Log_name" : "abc-bin.000001", "Pos" : 415, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 730, "Info" : "use `abc1`; CREATE TABLE `tb1` (\n `ID` bigint(20) unsigned NOT NULL,\n `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL,\n `lg` tinyint(1) unsigned NOT NULL DEFAULT '0',\n PRIMARY KEY (`ID`)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 730, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 795, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:3'" }, { "Log_name" : "abc-bin.000001", "Pos" : 795, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 867, "Info" : "BEGIN" }, { "Log_name" : "abc-bin.000001", "Pos" : 867, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 940, "Info" : "COMMIT" }, { "Log_name" : "abc-bin.000001", "Pos" : 940, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 1005, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:4'" }, { "Log_name" : "abc-bin.000001", "Pos" : 1005, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1273, "Info" : "use `abc1`; CREATE DEFINER=`root`@`%` TRIGGER `abc1`.`tb1_AFTER_INSERT` AFTER INSERT ON `tb1` FOR EACH ROW\nBEGIN\n\nif new.lg=1 then \ninsert into tb2 (ID,DID,DT) VALUES (NEW.ID,NEW.ID,NEW.DT);\nend if;\nEND" }, { "Log_name" : "abc-bin.000001", "Pos" : 1273, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 1338, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:5'" }, { "Log_name" : "abc-bin.000001", "Pos" : 1338, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1759, "Info" : "use `abc1`; CREATE TABLE `tb2` (\n `ID` bigint(20) unsigned NOT NULL,\n `DID` bigint(20) unsigned NOT NULL,\n `DT` varchar(50) COLLATE utf8_unicode_ci NOT NULL,\n PRIMARY KEY (`ID`),\n KEY `IDX` (`DID`) USING BTREE,\n CONSTRAINT `IDXFK` FOREIGN KEY (`DID`) REFERENCES `tb1` (`ID`) ON UPDATE CASCADE\n) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci" }, { "Log_name" : "abc-bin.000001", "Pos" : 1759, "Event_type" : "Gtid", "Server_id" : 100, "End_log_pos" : 1824, "Info" : "SET @@SESSION.GTID_NEXT= 'a3ec7103-4809-11e8-8994-521584a32842:6'" }, { "Log_name" : "abc-bin.000001", "Pos" : 1824, "Event_type" : "Query", "Server_id" : 100, "End_log_pos" : 1887, "Info" : "BEGIN" }, { "Log_name" : "abc-bin.000001", "Pos" : 1887, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 1937, "Info" : "table_id: 115 (abc1.tb2)" }, { "Log_name" : "abc-bin.000001", "Pos" : 1937, "Event_type" : "Table_map", "Server_id" : 100, "End_log_pos" : 1987, "Info" : "table_id: 114 (abc1.tb1)" }, { "Log_name" : "abc-bin.000001", "Pos" : 1987, "Event_type" : "Write_rows", "Server_id" : 100, "End_log_pos" : 2040, "Info" : "table_id: 114" }, { "Log_name" : "abc-bin.000001", "Pos" : 2040, "Event_type" : "Write_rows", "Server_id" : 100, "End_log_pos" : 2100, "Info" : "table_id: 115 flags: STMT_END_F" }, { "Log_name" : "abc-bin.000001", "Pos" : 2100, "Event_type" : "Xid", "Server_id" : 100, "End_log_pos" : 2131, "Info" : "COMMIT /* xid=131 */" }, { "Log_name" : "abc-bin.000001", "Pos" : 2131, "Event_type" : "Gtid", "Server_id" : 1000, "End_log_pos" : 2196, "Info" : "SET @@SESSION.GTID_NEXT= 'eca0e7c5-6b40-11e7-9267-18dbf2334ed5:1'" }, { "Log_name" : "abc-bin.000001", "Pos" : 2196, "Event_type" : "Query", "Server_id" : 1000, "End_log_pos" : 2354, "Info" : "use `abc1`; alter TABLE `tb2` change column DT `DT` varchar(45) COLLATE utf8_unicode_ci NOT NULL" } ]
[21 Jan 2019 7:24]
Jean-François Gagné
I have not read everything above, too many comments and not enough time on my side, but... Could this be related to slave_type_conversions ? IMHO, for this to work, slave_type_conversions should be set to ALL_NON_LOSSY or ALL_LOSSY as you are replicating from a column that can store more data to a cloumn that can store less data. Mohamed: can you share with us the value of slave_type_conversions on the slave ? It is easier to understand this with numbers. If you replicate an INT to a TINYINT, you could loose data (1024 will fit in an INT but not in a TINY INT). More details in [1]. [1]: https://dev.mysql.com/doc/mysql-replication-excerpt/5.7/en/replication-features-different-...
[21 Jan 2019 8:38]
mohamed atef
[21 Jan 7:24] Jean-François Gagné I have not read everything above, too many comments and not enough time on my side, but... Could this be related to slave_type_conversions ? IMHO, for this to work, slave_type_conversions should be set to ALL_NON_LOSSY or ALL_LOSSY as you are replicating from a column that can store more data to a cloumn that can store less data. Mohamed: can you share with us the value of slave_type_conversions on the slave ? It is easier to understand this with numbers. If you replicate an INT to a TINYINT, you could loose data (1024 will fit in an INT but not in a TINY INT). More details in [1]. ########################### thank you for the comment but you didn`t get the actual problem i know that when column change from varchar(50) to varchar(45) there is data loss but this will be right if the table have write row event from master but the table have only table map event from master my question here why the master send table map event while no write row event this happen if the table is mentioned in trigger in other table even there is if condition and the if condition is false ??????????????????????????
[30 Jan 2019 14:07]
MySQL Verification Team
Hi, This is rather weird situation, I was not able to properly reproduce on the normal system, the only place I see this table map when I don't expect it on ring replication between two windows instances of mysql. Why/How I'm out of ideas but verifying this. Thanks for the report Bogdan