Bug #102945 MTS fail due to ignore stop event when logical timestamp reset on new binary fil
Submitted: 12 Mar 8:04 Modified: 29 Mar 10:29
Reporter: Ray Jung Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:mysql.5.7 OS:Any
Assigned to: CPU Architecture:Any
Tags: binlog, MTS

[12 Mar 8:04] Ray Jung
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.
[29 Mar 10:29] MySQL Verification Team
Hi,

Thanks for the report

all best
Bogdan
[3 Aug 16:50] Greg Fury
I'm hitting this on MySQL 5.7.35.

Using parallel apply for point-in-time recovery.  This prevents us from recovering through a server restart.

Is there a workaround?