Scenario 1: Identical Binlog Filename with Misaligned Offsets

When utilizing a Virtual IP (VIP) for high availability, if the current primary and standby nodes share the exact same binary log filename, but the recorded position on the original primary is smaller than the actual position on the newly promoted primary, Canal throws an error resembling the following:

2023-11-15 10:15:09,332 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=10.0.5.1,reportPort=63292,reportUser=canal_sync_acct,reportPasswd=secret,serverId=55001,command=21]
2023-11-15 10:15:21,227 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=4450,slaveServerId=55001,binlogFileName=db-repl-log.000104,command=18]
2023-11-15 10:15:24,979 ERROR [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] DirectLogFetcher:163 | I/O error reading from client socket
java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = log event entry exceeded max_allowed_packet; Increase max_allowed_packet on master; the first event 'db-repl-log.000104' at 4450, the last event read from '/var/lib/mysql/db-repl-log.000104' at 120, the last byte read from '/var/lib/mysql/db-repl-log.000104' at 4500.
    at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102)
    at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:169)

This exception is intricately linked to the max_allowed_packet setting. This parameter governs the maximum size of a single binary log event transmitted during replication and must be a multiple of 1024. Two primary factors trigger this issue:

• Parameter Inconsistency: The max_allowed_packet value differs between the primary and replica nodes. If an event transmitted from the primary surpasses the limit configured on either node, the connection terminates. Verify consistency by executing: SHOW GLOBAL VARIABLES LIKE 'max_allowed_packet';
• Invalid Offset: The target position simply does not exist within the specified binary log file. Inspecting the file via the mysqlbinlog utility reveals that offset 4450 is absent. The resolution involves redirecting Canal to a valid, existing position.

mysqlbinlog db-repl-log.000104 --stop-position=4800

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 120
#231115 10:15:09 server id 2  end_log_pos 240 CRC32 0x87e4bed6     Start: binlog v 4, server v 5.7.30-log created 231115 10:15:09
BINLOG '
xfb6Xg8CAAAAdwAAAHsAAAABAAQANS43LjMwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
Ada+5Ic=
'/*!*/;
# at 240
#231115 10:15:09 server id 2  end_log_pos 350 CRC32 0xd95db8f4     Previous-GTIDs
# a1b2c3d4-e5f6-11ea-9b67-000c2915fd70:51-55
# at 350
#231115 10:20:23 server id 1  end_log_pos 415 CRC32 0x0ed285db     GTID    last_committed=0    sequence_number=1    rbr_only=yes
SET @@SESSION.GTID_NEXT= 'a1b2c3d4-e5f6-11ea-a64a-000c29ab1835:53'/*!*/;
# at 415
#231115 10:20:23 server id 1  end_log_pos 480 CRC32 0x34ec0ffb     Query    thread_id=11    exec_time=0    error_code=0
SET TIMESTAMP=1700000000/*!*/;
BEGIN
/*!*/;
# at 480
#231115 10:20:23 server id 1  end_log_pos 545 CRC32 0x62a09b2f     Table_map: `inventory`.`product_catalog` mapped to number 114
# at 545
#231115 10:20:23 server id 1  end_log_pos 610 CRC32 0x0f349879     Write_rows: table id 114 flags: STMT_END_F
BINLOG '
8/b6XhMBAAAAQQAAAKsBAAAAAHIAAAAAAAEABGludmVudG9yeQARcHJvZHVjdF9jYXRhbG9nAAMIDxE=
'/*!*/;
# at 610
#231115 10:20:23 server id 1  end_log_pos 641 CRC32 0x9d38dbb3     Xid = 542
COMMIT/*!*/;

Scenario 2: Requested Offset Exceeds File Size

During a database failover, irrespective of whether the binary log filenames align, if the recorded position from the original primary is larger than the current size of the binary log on the new primary, the following failure occurs:

2023-11-15 09:51:16,671 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=10.0.5.1,reportPort=60838,reportUser=canal_sync_acct,reportPasswd=secret,serverId=55001,command=21]
2023-11-15 09:51:16,671 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=89500,slaveServerId=55001,binlogFileName=db-repl-log.000104,command=18]
2023-11-15 09:51:16,672 ERROR [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] DirectLogFetcher:163 | I/O error reading from client socket
java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = Client requested master to start replication from position > file size
    at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102)
    at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:169)

The error message explicitly indicates that the replication client is attempting to start reading from an offset that surpasses the actual physical size of the binary log file on the newly promoted primary server.

Scenario 3: Binlog Sequence Number Mismatch

If the binary log sequence index on the original primary is numerically higher than the sequence index on the newly promoted primary (e.g., the old primary is at db-repl-log.000106 while the new primary is at db-repl-log.000104), Canal will log this error:

2023-11-16 11:35:07,977 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=10.0.5.1,reportPort=59469,reportUser=canal_sync_acct,reportPasswd=secret,serverId=55001,command=21]
2023-11-16 11:35:07,978 INFO [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=4450,slaveServerId=55001,binlogFileName=db-repl-log.000106,command=18]
2023-11-16 11:35:07,979 ERROR [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] DirectLogFetcher:163 | I/O error reading from client socket
java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = Could not find first log file name in binary log index file
    at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102)
    at com.alibaba.otter.canal.parse.inbound.mysql.MysqlConnection.dump(MysqlConnection.java:169)

This signifies that the new primary node has undergone fewer log rotations. Consequently, it does not possess a binary log file with the higher sequence number requested by Canal.

Scenario 4: Referencing Purged Binary Logs

Attempting to replicate from a binary log file that has already been deleted or purged from the server's disk results in a similar "file not found" error:

2023-11-16 18:07:53,443 WARN [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlEventParser:456 | prepare to find start position db-repl-log.000100:4:1700000000000
2023-11-16 18:07:53,443 WARN [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] MysqlEventParser:205 | ---> find start position successfully, EntryPosition[included=false,journalName=db-repl-log.000100,position=4,serverId=null,gtid=null,timestamp=1700000000000] cost : 40ms , the next step is binlog dump
...
2023-11-16 18:07:53,460 ERROR [dest = cluster-A , addr = /10.0.5.200:3307 , EventParser] DirectLogFetcher:163 | I/O error reading from client socket
java.io.IOException: Received error packet: errno = 1236, sqlstate = HY000 errmsg = Could not find first log file name in binary log index file
    at com.alibaba.otter.canal.parse.inbound.mysql.dbsync.DirectLogFetcher.fetch(DirectLogFetcher.java:102)

To recover from this state, execute the FLUSH LOGS command on the active primary to force the creation of a fresh binary log file. Subsequently, query the current coodrinates using SHOW MASTER STATUS, and reconfigure the replication connection using the updated details:

CHANGE REPLICATION SOURCE TO
    SOURCE_LOG_FILE='db-repl-log.000101',
    SOURCE_LOG_POS=156;