108.Replica I/O for channel log event entry exceeded max_allowed_packet

1.现象

stop slave; 

start slave; 

关闭mysql8.0.34从库的同步，过了一会开启后，报错。

2024-01-15T14:59:30.908874+08:00 1186 [Warning] [MY-010897] [Repl] Storing MySQL user name or password information in the connection metadata repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START REPLICA; see the 'START REPLICA Syntax' in the MySQL Manual for more information.
2024-01-15T14:59:30.910166+08:00 1186 [ERROR] [MY-010584] [Repl] Replica I/O for channel '': Error connecting to source 'repl@10.1.12.47:3300'. This was attempt 1/86400, with a delay of 60 seconds between attempts. Message: Authentication plugin 'caching_sha2_password' reported error: Authentication requires secure connection. Error_code: MY-002061

2.根据BINLOG和POS重新同步

CHANGE MASTER TO
source_host='10.1.1.1',
source_port =3300,
source_user='repl',
source_password='repl',
source_log_file='binlog.000017',
source_log_pos=481505221 ,
get_master_public_key=1;

2024-01-15T16:13:11.577313+08:00 1341 [ERROR] 
[MY-013114] [Repl] Replica I/O for channel '': 
Got fatal error 1236 from source when reading data from binary log: 
'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on source; 
the first event 'binlog.000017' at 481505221, 
the last event read from '/chac/mysql/mysql3300/logs/binlog.000017' at 126, 
the last byte  read from '/chac/mysql/mysql3300/logs/binlog.000017' at 481505240.', 
Error_code: MY-013114

log event entry exceeded max_allowed_packet; Increase max_allowed_packet on source;

原因是指定的POS 在BINLOG里面不存在，起初以为是max_allowed_packet过小，但是修改并没有用。

BINLOG内容查看:合适的位置应该从:# at 481505175 这里开始。

# at 481505175
#240115 14:55:05 server id 13300  end_log_pos 481505381 CRC32 0xdb9074e7 	Rows_query
# UPDATE QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1705301705283 WHERE SCHED_NAME = 'clusteredScheduler' AND INSTANCE_NAME = 'callcenter-prod-service-access-1-202311021702997616912'
# at 481505381
#240115 14:55:05 server id 13300  end_log_pos 481505460 CRC32 0x93d59607 	Table_map: `newfs`.`qrtz_scheduler_state` mapped to number 932
# has_generated_invisible_primary_key=0
# at 481505460
#240115 14:55:05 server id 13300  end_log_pos 481505682 CRC32 0x763756f1 	Update_rows: table id 932 flags: STMT_END_F
### UPDATE `newfs`.`qrtz_scheduler_state`
### WHERE
###   @1='clusteredScheduler' /* VARSTRING(480) meta=480 nullable=0 is_null=0 */
###   @2='callcenter-prod-service-access-1-202311021702997616912' /* VARSTRING(800) meta=800 nullable=0 is_null=0 */
###   @3=1705301704275 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=1000 /* LONGINT meta=0 nullable=0 is_null=0 */
### SET
###   @1='clusteredScheduler' /* VARSTRING(480) meta=480 nullable=0 is_null=0 */
###   @2='callcenter-prod-service-access-1-202311021702997616912' /* VARSTRING(800) meta=800 nullable=0 is_null=0 */
###   @3=1705301705283 /* LONGINT meta=0 nullable=0 is_null=0 */
###   @4=1000 /* LONGINT meta=0 nullable=0 is_null=0 */

--binlog中找到对应的SQL;手工执行。
# at 481505175 --对应的SQL;
UPDATE newfs.QRTZ_SCHEDULER_STATE SET LAST_CHECKIN_TIME = 1705301705283 WHERE SCHED_NAME = 'clusteredScheduler' AND INSTANCE_NAME = 'callcenter-prod-service-access-1-202311021702997616912';
SET @@SESSION.GTID_NEXT= '20e43bc1-48a8-11ee-8646-005056a76880:9478113';

3.从下一个POS重新同步

CHANGE REPLICATION SOURCE TO
source_host='10.1.12.47',
source_port =3300,
source_user='repl',
source_password='repl4slave',
source_log_file='binlog.000017',
source_log_pos=481505381 ;

又报错:

--GTID_MODE=ON 时,无法修改为:ANONYMOUS
2024-01-15T17:12:39.197088+08:00 1423 [ERROR] [MY-010584] 
[Repl] Replica SQL for channel '': Worker 1 failed executing transaction 'NOT_YET_DETERMINED' 
at source log binlog.000017, end_log_pos 481505682; 
Error executing row event: '@@SESSION.GTID_NEXT cannot be set to ANONYMOUS when @@GLOBAL.GTID_MODE = ON.', 
Error_code: MY-001782

GTID_MODE修改为:ON_PERMISSIVE ,再次启动正常修复。

mysql> SET GLOBAL GTID_MODE = 'ON_PERMISSIVE';
Query OK, 0 rows affected (0.00 sec)

mysql> start slave; 
Query OK, 0 rows affected, 1 warning (0.01 sec)

mysql> show slave status\G;
*************************** 1. row ***************************
               Slave_IO_State: Waiting for source to send event
                  Master_Host: 10.1.1.1
                  Master_User: repl
                  Master_Port: 3300
                Connect_Retry: 60
              Master_Log_File: binlog.000018
          Read_Master_Log_Pos: 15555760
               Relay_Log_File: callcenter-prod-database-mysql8-slave-1-20231102-relay-bin.000002
                Relay_Log_Pos: 1273850
        Relay_Master_Log_File: binlog.000017
             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: 482778908
              Relay_Log_Space: 34038981
              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: 8119
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: 13300
                  Master_UUID: 20e43bc1-48a8-11ee-8646-005056a76880
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: Waiting for dependent transaction to commit
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 20e43bc1-48a8-11ee-8646-005056a76880:9478113-9514380
            Executed_Gtid_Set: 028293be-8dcc-11ee-bcdc-005056bf902f:1,
20e43bc1-48a8-11ee-8646-005056a76880:9478113-9479439
                Auto_Position: 0
         Replicate_Rewrite_DB: 
                 Channel_Name: 
           Master_TLS_Version: 
       Master_public_key_path: 
        Get_master_public_key: 0
            Network_Namespace: 
1 row in set, 1 warning (0.00 sec)

3.总结 

log event entry exceeded max_allowed_packet， 这个报错的原因是指定的binlog的pos不对。

修复后:

stop slave; 
SET GLOBAL GTID_MODE = 'ON';
start slave;