Description:
I was doing parallel replication using binlog, but was failed. (using 2 binlog, mysql-binlog.000001,mysql-binlog.000002)
Succeed case)
Call rotate evnet (Flush log) is OK
Fail case)
STOP(restart mysqld) event making mysql-binlog.000002 and sequence_number, last_committed is reset in mysql-binlog.000002.
but MTS expecting old sequence_number
error log)
2021-03-11T14:42:00.200875Z 8 [ERROR] Transaction's sequence number is inconsistent with that of a preceding one: sequence_number (1) <= previous sequence_number (85)
2021-03-11T14:42:00.200893Z 8 [Warning] Slave SQL for channel '': Coordinator thread of multi-threaded slave is being stopped in the middle of assigning a group of events;
deferring to exit until the group completion ... , Error_code: 0
2021-03-11T14:42:00.200900Z 8 [ERROR] Slave SQL for channel '': Cannot execute the current event group in the parallel mode.
Encountered event Gtid, relay-log name /restore/tmp/binlog/mysql-bin.000002, position 194 which prevents execution of this event group in parallel mode.
Reason: The master event is logically timestamped incorrectly.. Error_code: 1755
2021-03-11T14:42:00.200905Z 8 [Warning] Slave: Cannot execute the current event group in the parallel mode.
Encountered event Gtid, relay-log name /restore/tmp/binlog/mysql-bin.000002,
position 194 which prevents execution of this event group in parallel mode. Reason: The master event is logically timestamped incorrectly.. Error_code: 1755
2021-03-11T14:42:00.200908Z 8 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'FIRST' position 123
mysql-binlog.000001]
---------------------------------------------------------------------------------------------------------------------------------------------
#210311 13:59:29 server id 2194521 end_log_pos 22709 CRC32 0x71f335e9 Query thread_id=349 exec_time=0 error_code=0
SET TIMESTAMP=1615471169/*!*/;
BEGIN
/*!*/;
# at 22709
#210311 13:59:29 server id 2194521 end_log_pos 22764 CRC32 0xef6710a4 Table_map: `cdsp`.`repl_check` mapped to number 119
# at 22764
#210311 13:59:29 server id 2194521 end_log_pos 22820 CRC32 0xb3f54706 Update_rows: table id 119 flags: STMT_END_F
# at 22820
#210311 13:59:29 server id 2194521 end_log_pos 22851 CRC32 0x21546da8 Xid = 677
COMMIT/*!*/;
# at 22851
#210311 13:59:34 server id 2241178 end_log_pos 22874 CRC32 0xeca5a818 Stop
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*/;
mysql-binlog.000002]
---------------------------------------------------------------------------------------------------------------------------------------------
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#210311 14:02:56 server id 2241178 end_log_pos 123 CRC32 0xa8adf8c3 Start: binlog v 4, server v 5.7.21-20-57-log created 210311 14:02:56 at startup
ROLLBACK/*!*/;
# at 123
#210311 14:02:56 server id 2241178 end_log_pos 194 CRC32 0x3308a4dd Previous-GTIDs
# 62783bfa-7ffe-11eb-a8ee-aa50ac1f2bb8:49-133
# at 194
#210311 14:03:57 server id 2241178 end_log_pos 259 CRC32 0x39937f99 GTID last_committed=0 sequence_number=1 rbr_only=no
SET @@SESSION.GTID_NEXT= 'c0193eb2-8271-11eb-81fb-3223ac1f8b60:1'/*!*/;
How to repeat:
1) Master-slave
2) slave restart (==maybe we have 000001, 000002 )
3) using slave binlog , CHANGE MASTER TO MASTER_HOST='dummy',RELAY_LOG_FILE='mysql-bin.000001',RELAY_LOG_POS=xxxx with
SLAVE_PARALLEL_TYPE='LOGICAL_CLOCK' and SLAVE_PARALLEL_WORKERS >0
Suggested fix:
treat STOP event as Rotate event.
