关于mysql主备切换canal出现的问题解决

通过配置VIP，在进行主备切换时，出现的报错信息：

1.当主备节点当前binlog文件名称相同时，原主节点的position小于主备切换后的position，出现如下报错：

2020-07-02 15:08:09,332 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=192.168.3.1,reportPort=63292,reportUser=canal_repl_user,reportPasswd=111111,serverId=10236,command=21]2020-07-02 15:08:21,227 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=1104,slaveServerId=10236,binlogFileName=mysql-bin.000002,command=18]2020-07-02 15:08:24,979 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] LogEvent:122 | common_header_len= 19, number_of_event_types= 382020-07-02 15:08:24,983 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] DirectLogFetcher:163 | I/O error while reading from client socketjava.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 'mysql-bin.000002' at 1104, the last event read from '/usr/local/mysql/logs/mysql-bin.000002' at 123, the last byte read from '/usr/local/mysql/logs/mysql-bin.000002' at 1123. 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-02 15:08:24,989 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:301 | dump address 192.168.3.100/192.168.3.100:3306 has an error, retrying. caused by 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 'mysql-bin.000002' at 1104, the last event read from '/usr/local/mysql/logs/mysql-bin.000002' at 123, the last byte read from '/usr/local/mysql/logs/mysql-bin.000002' at 1123. 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-02 15:08:24,994 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] LogAlarmHandler:19 | destination:1-236[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 'mysql-bin.000002' at 1104, the last event read from '/usr/local/mysql/logs/mysql-bin.000002' at 123, the last byte read from '/usr/local/mysql/logs/mysql-bin.000002' at 1123. 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)]

1>.该参数在主备库的配置大小不一致。从主库传递到备库的binlog event大小超过了主库或者备库的max_allowed_packet大小。可以查看变量值：SHOW GLOBAL VARIABLES LIKE "%max_allowed_packet%"; 看两个库的值是否一致。

2>.在对应个binlog文件中找不到对应的偏移量position，可以通过mysqlbinlog命令查看，发现没有要报错要找的1104(position)，可以切换到存在的position位点

mysqlbinlog mysql-bin.000002 --stop-position=1200/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;DELIMITER /*!*/;# at 4#200630 16:24:37 server id 2 end_log_pos 123 CRC32 0x87e4bed6  Start: binlog v 4, server v 5.7.28-log created 200630 16:24:37# Warning: this binlog is either in use or was not closed properly.BINLOG 'xfb6Xg8CAAAAdwAAAHsAAAABAAQANS43LjI4LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQAAda+5Ic='/*!*/;# at 123#200630 16:24:37 server id 2 end_log_pos 234 CRC32 0xd95db8f4  Previous-GTIDs# b3a0925e-b78b-11ea-9b67-000c2915fd70:51-55,# b85582c3-14d9-11ea-a64a-000c29ab1835:40-52# at 234#200630 16:25:23 server id 1 end_log_pos 299 CRC32 0x0ed285db  GTID last_committed=0 sequence_number=1 rbr_only=yes/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;SET @@SESSION.GTID_NEXT= 'b85582c3-14d9-11ea-a64a-000c29ab1835:53'/*!*/;# at 299#200630 16:25:23 server id 1 end_log_pos 362 CRC32 0x34ec0ffb  Query thread_id=11 exec_time=0 error_code=0SET TIMESTAMP=1593505523/*!*/;SET @@session.pseudo_thread_id=11/*!*/;SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;SET @@session.sql_mode=524288/*!*/;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=33/*!*/;SET @@session.lc_time_names=0/*!*/;SET @@session.collation_database=DEFAULT/*!*/;BEGIN/*!*/;# at 362#200630 16:25:23 server id 1 end_log_pos 427 CRC32 0x62a09b2f  Table_map: `test`.`test_canal_2_hive` mapped to number 114# at 427#200630 16:25:23 server id 1 end_log_pos 492 CRC32 0x0f349879  Write_rows: table id 114 flags: STMT_END_FBINLOG '8/b6XhMBAAAAQQAAAKsBAAAAAHIAAAAAAAEABHRlc3QAEXRlc3RfY2FuYWxfMl9oaXZlAAMIDxEDUAAABi+boGI=8/b6Xh4BAAAAQQAAAOwBAAAAAHIAAAAAAAEAAgAD//iYAAAAAAAAABB6aGFuZ3Nhbi0wMS1zMTI5Xvr283mYNA8='/*!*/;# at 492#200630 16:25:23 server id 1 end_log_pos 523 CRC32 0x9d38dbb3  Xid = 542COMMIT/*!*/;# at 523#200630 16:31:33 server id 1 end_log_pos 588 CRC32 0x7a71df00  GTID last_committed=1 sequence_number=2 rbr_only=yes/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;SET @@SESSION.GTID_NEXT= 'b85582c3-14d9-11ea-a64a-000c29ab1835:54'/*!*/;# at 588#200630 16:31:33 server id 1 end_log_pos 651 CRC32 0xec353d4a  Query thread_id=11 exec_time=0 error_code=0SET TIMESTAMP=1593505893/*!*/;BEGIN/*!*/;# at 651#200630 16:31:33 server id 1 end_log_pos 716 CRC32 0x0309e1d5  Table_map: `test`.`test_canal_2_hive` mapped to number 114# at 716#200630 16:31:33 server id 1 end_log_pos 781 CRC32 0xb7ac4767  Write_rows: table id 114 flags: STMT_END_FBINLOG 'Zfj6XhMBAAAAQQAAAMwCAAAAAHIAAAAAAAEABHRlc3QAEXRlc3RfY2FuYWxfMl9oaXZlAAMIDxEDUAAABtXhCQM=Zfj6Xh4BAAAAQQAAAA0DAAAAAHIAAAAAAAEAAgAD//iZAAAAAAAAABB6aGFuZ3Nhbi0wMS1zMTI5Xvr4ZWdHrLc='/*!*/;# at 781#200630 16:31:33 server id 1 end_log_pos 812 CRC32 0xa8c3ce12  Xid = 550COMMIT/*!*/;# at 812#200630 16:52:25 server id 1 end_log_pos 877 CRC32 0x8e7366ee  GTID last_committed=2 sequence_number=3 rbr_only=noSET @@SESSION.GTID_NEXT= 'b85582c3-14d9-11ea-a64a-000c29ab1835:55'/*!*/;# at 877#200630 16:52:25 server id 1 end_log_pos 1122 CRC32 0xb5c35333  Query thread_id=11 exec_time=0 error_code=0use `test`/*!*/;SET TIMESTAMP=1593507145/*!*/;SET @@session.sql_mode=1436549152/*!*/;GRANT REPLICATION SLAVE, REPLICATION CLIENT ON *.* TO 'canal_repl_user'@'%' IDENTIFIED WITH 'mysql_native_password' AS '*FD571203974BA9AFE270FE62151AE967ECA5E0AA'/*!*/;# at 1122#200630 16:52:29 server id 1 end_log_pos 1187 CRC32 0x2f039a0c  GTID last_committed=3 sequence_number=4 rbr_only=noSET @@SESSION.GTID_NEXT= 'b85582c3-14d9-11ea-a64a-000c29ab1835:56'/*!*/;# at 1187#200630 16:52:29 server id 1 end_log_pos 1278 CRC32 0x0348011d  Query thread_id=11 exec_time=0 error_code=0SET TIMESTAMP=1593507149/*!*/;SET @@session.time_zone='SYSTEM'/*!*/;flush privileges/*!*/;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*/;

2020-07-02 14:51:16,671 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=192.168.3.1,reportPort=60838,reportUser=canal_repl_user,reportPasswd=111111,serverId=10236,command=21]2020-07-02 14:51:16,671 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=10262,slaveServerId=10236,binlogFileName=mysql-bin.000002,command=18]2020-07-02 14:51:16,672 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] DirectLogFetcher:163 | I/O error while reading from client socketjava.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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-02 14:51:16,673 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:301 | dump address 192.168.3.100/192.168.3.100:3306 has an error, retrying. caused by 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-02 14:51:16,769 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] LogAlarmHandler:19 | destination:1-236[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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)]

3.mysql主备切换时，原主库binlog名称序号大于切换后主库binlog名称序号，会报如下错误：

2020-07-06 11:35:07,977 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=192.168.3.1,reportPort=59469,reportUser=canal_repl_user,reportPasswd=111111,serverId=10236,command=21]2020-07-06 11:35:07,978 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=1411,slaveServerId=10236,binlogFileName=mysql-bin.000003,command=18]2020-07-06 11:35:07,979 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] DirectLogFetcher:163 | I/O error while reading from client socketjava.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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-06 11:35:07,980 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:301 | dump address 192.168.3.100/192.168.3.100:3306 has an error, retrying. caused by 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-06 11:35:07,987 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] LogAlarmHandler:19 | destination:1-236[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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)]

3.使用删除的binlog文件名称，报如下错误：

2020-07-03 18:07:53,443 WARN [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:456 | prepare to find start position mysql-bin.000001:4:15935078610002020-07-03 18:07:53,443 WARN [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:205 | ---> find start position successfully, EntryPosition[included=false,journalName=mysql-bin.000001,position=4,serverId=<null>,gtid=<null>,timestamp=1593507861000] cost : 40ms , the next step is binlog dump2020-07-03 18:07:53,444 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnector:101 | disConnect MysqlConnection to /192.168.3.100:3306...2020-07-03 18:07:53,446 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnector:79 | connect MysqlConnection to /192.168.3.100:3306...2020-07-03 18:07:53,447 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnector:182 | handshake initialization packet received, prepare the client authentication packet to send2020-07-03 18:07:53,447 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnector:199 | client authentication packet is sent out.2020-07-03 18:07:53,458 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:293 | Register slave RegisterSlaveCommandPacket[reportHost=192.168.3.1,reportPort=49875,reportUser=canal_repl_user,reportPasswd=111111,serverId=10236,command=21]2020-07-03 18:07:53,459 INFO [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlConnection:321 | COM_BINLOG_DUMP with position:BinlogDumpCommandPacket[binlogPosition=4,slaveServerId=10236,binlogFileName=mysql-bin.000001,command=18]2020-07-03 18:07:53,460 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] DirectLogFetcher:163 | I/O error while reading from client socketjava.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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-03 18:07:53,462 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] MysqlEventParser:301 | dump address /192.168.3.100:3306 has an error, retrying. caused by 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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)2020-07-03 18:07:53,463 ERROR [destination = 1-236 , address = /192.168.3.100:3306 , EventParser] LogAlarmHandler:19 | destination:1-236[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) at com.alibaba.otter.canal.parse.inbound.AbstractEventParser$3.run(AbstractEventParser.java:279) at java.lang.Thread.run(Thread.java:748)]

总结

更多相关文章

随机推荐