尝试运行连接器类“io.debezium.connector.mysql.MySqlConnector”时出错

Posted 2023-03-23

【中文标题】尝试运行连接器类“io.debezium.connector.mysql.MySqlConnector”时出错

【英文标题】：Error while trying to run connector class 'io.debezium.connector.mysql.MySqlConnector'

【发布时间】：2021-09-29 14:17:46

【问题描述】：

我们有一个与 Kafka/Debezium 集成的 Java 11 Spring Boot 应用程序。

在 mysql (5.7) 数据库上进行了数据库更改（用户删除/使用数据重新创建表）Debezium 的 binlogreader 开始读取 bin 日志，但随后记录以下异常

2021-07-22 10:05:08.584  INFO 24570 --- [debyte.com:3306] i.d.r.history.DatabaseHistoryMetrics     : Already applied 10969 database changes
2021-07-22 10:05:10.134 ERROR 24570 --- [debyte.com:3306] i.debezium.connector.mysql.BinlogReader  : Error while deserializing binlog event at offset ts_sec=1626941231, file=mysql-bin.000532, pos=75496603, server_id=2001, event=876.
Use the mysqlbinlog tool to view the problematic event: mysqlbinlog --start-position=82610388 --stop-position=82618497 --verbose mysql-bin.000532
2021-07-22 10:05:10.135 ERROR 24570 --- [debyte.com:3306] i.debezium.connector.mysql.BinlogReader  : Error during binlog processing. Last offset stored = ts_sec=1626941227, file=mysql-bin.000532, pos=71066122, row=272, server_id=2001, event=518, binlog reader near position = mysql-bin.000532/82610388
2021-07-22 10:05:10.150 ERROR 24570 --- [debyte.com:3306] i.debezium.connector.mysql.BinlogReader  : Failed due to error: Error processing binlog event

org.apache.kafka.connect.errors.ConnectException: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4timestamp=1626941231000, eventType=EXT_WRITE_ROWS, serverId=2001, headerLength=19, dataLength=8090, nextPosition=82618497, flags=0
    at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:536) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1158) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1005) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connectWithTimeout(BinaryLogClient.java:517) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.access$1100(BinaryLogClient.java:90) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:881) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]
Caused by: java.lang.RuntimeException: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4timestamp=1626941231000, eventType=EXT_WRITE_ROWS, serverId=2001, headerLength=19, dataLength=8090, nextPosition=82618497, flags=0
    at io.debezium.connector.mysql.BinlogReader.handleServerIncident(BinlogReader.java:604) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:519) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    ... 6 common frames omitted
Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4timestamp=1626941231000, eventType=EXT_WRITE_ROWS, serverId=2001, headerLength=19, dataLength=8090, nextPosition=82618497, flags=0
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:300) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:223) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at io.debezium.connector.mysql.BinlogReader$1.nextEvent(BinlogReader.java:239) ~[debezium-connector-mysql-1.0.0.Final.jar:1.0.0.Final]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:984) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    ... 4 common frames omitted
Caused by: java.io.EOFException: null
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:190) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at java.base/java.io.InputStream.read(InputStream.java:271) ~[na:na]
    at java.base/java.io.InputStream.skip(InputStream.java:531) ~[na:na]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.skipToTheEndOfTheBlock(ByteArrayInputStream.java:216) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:296) ~[mysql-binlog-connector-java-0.21.0.jar:0.21.0]
    ... 7 common frames omitted

2021-07-22 10:05:10.150  INFO 24570 --- [debyte.com:3306] i.debezium.connector.mysql.BinlogReader  : Error processing binlog event, and propagating to Kafka Connect so it stops this connector. Future binlog events read before connector is shutdown will be ignored.
2021-07-22 10:05:10.152  INFO 24570 --- [debyte.com:3306] i.debezium.connector.mysql.BinlogReader  : Stopped reading binlog after 167936 events, last recorded offset: ts_sec=1626941227, file=mysql-bin.000532, pos=71066122, row=272, server_id=2001, event=518
2021-07-22 10:05:37.521  INFO 24570 --- [pool-1-thread-1] i.d.connector.mysql.MySqlConnectorTask   : Stopping MySQL connector task

这也是在应用程序启动时记录的。

建议的mysqlbinlog命令：

mysqlbinlog --start-position=82610388 --stop-position=82618497 --verbose mysql-bin.000532

返回

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#210722  8:06:26 server id 2001  end_log_pos 123 CRC32 0xc7bff6dc   Start: binlog v 4, server v 5.7.19-log created 210722  8:06:26
BINLOG '
Aif5YA/RBwAAdwAAAHsAAAAAAAQANS43LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
Adz2v8c=
'/*!*/;
# at 82610388
#210722  8:07:11 server id 2001  end_log_pos 82618497 CRC32 0xd2561ccc  Write_rows: table id 43469
WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
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*/;

我不知道为什么会发生这种情况，也不知道如何围绕它编写代码。错误不会向应用程序抛出。

还有其他人遇到过类似的问题吗？

【参考方案1】：

我在debezium's doc找到了解决方案：

是什么导致 MySQL 连接器出现间歇性 EventDataDeserializationExceptions？

当您在启动连接器大约 1 分钟后遇到间歇性反序列化异常时，其根本原因类型为 EOFException 或 java.net.SocketException: Connection reset：

Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializati>onException: Failed to deserialize data of EventHeaderV4timestamp=1542193955000, eventType=GTID, serverId=91111, headerLength=19, dataLength=46, nextPosition=1058898202, flags=0
Caused by: java.lang.RuntimeException: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4timestamp=1542193955000, eventType=GTID, serverId=91111, headerLength=19, dataLength=46, nextPosition=1058898202, flags=0
Caused by: java.io.EOFException

or

Caused by: java.net.SocketException: Connection reset

然后像这样更新这些 MySQL 服务器全局属性将修复它：

set global slave_net_timeout = 120; (default was 30sec)
set global thread_pool_idle_timeout = 120;