search

apache / flink-cdc

Flink CDC is a streaming data integration tool
https://nightlies.apache.org/flink/flink-cdc-docs-stable
Apache License 2.0
5.71k stars 1.94k forks source link

[Bug] Failed to deserialize data of EventHeaderV4 #2307

Closed ByteInvoker closed 9 months ago

ByteInvoker commented 1 year ago

Search before asking

Flink version

1.4.4

Flink CDC version

2.3.0

Database and its version

mysql hbase

Minimal reproduce step

datastream方式同步mysql binlog数据到hbase ，全量阶段正常，增量阶段就出现这个问题

What did you expect to see?

正常运行

What did you see instead?

io.debezium.DebeziumException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.wrap(MySqlStreamingChangeEventSource.java:1489) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$ReaderThreadLifecycleListener.onCommunicationFailure(MySqlStreamingChangeEventSource.java:1545) [blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1079) [blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) [blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) [blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]
Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:341) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$1.nextEvent(MySqlStreamingChangeEventSource.java:260) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 3 more
Caused by: java.io.EOFException: Failed to read remaining 72 of 306 bytes from position 3501350. Block length: 72. Initial block length: 307.
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.fill(ByteArrayInputStream.java:115) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:105) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.readString(ByteArrayInputStream.java:78) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:31) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:25) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:335) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$1.nextEvent(MySqlStreamingChangeEventSource.java:260) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 3 more
2023-07-15 05:40:09,139 INFO  io.debezium.connector.mysql.MySqlStreamingChangeEventSource  [] - Stopped reading binlog after 0 events, last recorded offset: {transaction_id=null, ts_sec=1689370809, file=mysql-bin.003236, pos=206875134, gtids=3bf97d14-5b05-11eb-9205-1418774316c6:1-463425901,3d53a26f-5b05-11eb-baa5-14187743a0ac:1-1, server_id=683728822, event=1}
2023-07-15 05:40:09,493 ERROR org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherManager [] - Received uncaught exception.
java.lang.RuntimeException: SplitFetcher thread 1 received unexpected exception while polling the records
    at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher.runOnce(SplitFetcher.java:150) ~[flink-table_2.12-1.14.4.jar:1.14.4]
    at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher.run(SplitFetcher.java:105) [flink-table_2.12-1.14.4.jar:1.14.4]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_91]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_91]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_91]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_91]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]
Caused by: org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
    at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:50) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.ververica.cdc.connectors.mysql.debezium.task.context.MySqlErrorHandler.setProducerThrowable(MySqlErrorHandler.java:85) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$ReaderThreadLifecycleListener.onCommunicationFailure(MySqlStreamingChangeEventSource.java:1545) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1079) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 1 more
Caused by: io.debezium.DebeziumException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.wrap(MySqlStreamingChangeEventSource.java:1489) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$ReaderThreadLifecycleListener.onCommunicationFailure(MySqlStreamingChangeEventSource.java:1545) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1079) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 1 more
Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:341) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$1.nextEvent(MySqlStreamingChangeEventSource.java:260) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 1 more
Caused by: java.io.EOFException: Failed to read remaining 72 of 306 bytes from position 3501350. Block length: 72. Initial block length: 307.
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.fill(ByteArrayInputStream.java:115) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:105) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.readString(ByteArrayInputStream.java:78) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:31) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:25) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:335) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$1.nextEvent(MySqlStreamingChangeEventSource.java:260) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) ~[blob_p-daa0aaf6b57c704eb04b1630334fb2252930099a-5e7585dcfc95383a2ad6ee2b9c7f083f:?]
    ... 1 more
2023-07-15 05:40:09,498 INFO  io.debezium.jdbc.JdbcConnection                              [] - Connection gracefully closed
2023-07-15 05:40:09,505 INFO  org.apache.flink.runtime.checkpoint.channel.ChannelStateWriteRequestExecutorImpl [] - Source: buyLog Source -> Map -> Filter (1/1)#0 discarding 0 drained requests
2023-07-15 05:40:09,507 INFO  org.apache.flink.connector.base.source.reader.SourceReaderBase [] - Closing Source Reader.
2023-07-15 05:40:09,507 INFO  org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher [] - Shutting down split fetcher 1
2023-07-15 05:40:09,583 INFO  org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher [] - Split fetcher 1 exited.
2023-07-15 05:40:09,589 WARN  org.apache.flink.runtime.taskmanager.Task                    [] - Source: buyLog Source -> Map -> Filter (1/1)#0 (5d7feea00943b52487126cc748306286) switched from RUNNING to FAILED with failure cause: java.lang.RuntimeException: One or more fetchers have encountered exception
    at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcherManager.checkErrors(SplitFetcherManager.java:225)
    at org.apache.flink.connector.base.source.reader.SourceReaderBase.getNextFetch(SourceReaderBase.java:169)
    at org.apache.flink.connector.base.source.reader.SourceReaderBase.pollNext(SourceReaderBase.java:130)
    at org.apache.flink.streaming.api.operators.SourceOperator.emitNext(SourceOperator.java:351)
    at org.apache.flink.streaming.runtime.io.StreamTaskSourceInput.emitNext(StreamTaskSourceInput.java:68)
    at org.apache.flink.streaming.runtime.io.StreamOneInputProcessor.processInput(StreamOneInputProcessor.java:65)
    at org.apache.flink.streaming.runtime.tasks.StreamTask.processInput(StreamTask.java:496)
    at org.apache.flink.streaming.runtime.tasks.mailbox.MailboxProcessor.runMailboxLoop(MailboxProcessor.java:203)
    at org.apache.flink.streaming.runtime.tasks.StreamTask.runMailboxLoop(StreamTask.java:809)
    at org.apache.flink.streaming.runtime.tasks.StreamTask.invoke(StreamTask.java:761)
    at org.apache.flink.runtime.taskmanager.Task.runWithSystemExitMonitoring(Task.java:958)
    at org.apache.flink.runtime.taskmanager.Task.restoreAndInvoke(Task.java:937)
    at org.apache.flink.runtime.taskmanager.Task.doRun(Task.java:766)
    at org.apache.flink.runtime.taskmanager.Task.run(Task.java:575)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: SplitFetcher thread 1 received unexpected exception while polling the records
    at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher.runOnce(SplitFetcher.java:150)
    at org.apache.flink.connector.base.source.reader.fetcher.SplitFetcher.run(SplitFetcher.java:105)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    ... 1 more
Caused by: org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
    at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:50)
    at com.ververica.cdc.connectors.mysql.debezium.task.context.MySqlErrorHandler.setProducerThrowable(MySqlErrorHandler.java:85)
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$ReaderThreadLifecycleListener.onCommunicationFailure(MySqlStreamingChangeEventSource.java:1545)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1079)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631)
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932)
    ... 1 more
Caused by: io.debezium.DebeziumException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.wrap(MySqlStreamingChangeEventSource.java:1489)
    ... 5 more
Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4{timestamp=1689370731000, eventType=ROWS_QUERY, serverId=683728822, headerLength=19, dataLength=311, nextPosition=206875527, flags=128}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:341)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244)
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$1.nextEvent(MySqlStreamingChangeEventSource.java:260)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051)
    ... 3 more
Caused by: java.io.EOFException: Failed to read remaining 72 of 306 bytes from position 3501350. Block length: 72. Initial block length: 307.
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.fill(ByteArrayInputStream.java:115)
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:105)
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.readString(ByteArrayInputStream.java:78)
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:31)
    at com.github.shyiko.mysql.binlog.event.deserialization.RowsQueryEventDataDeserializer.deserialize(RowsQueryEventDataDeserializer.java:25)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:335)
    ... 6 more

Anything else?

有相关issues上说在2.X版本已修复，但是2.3版本依然有这个问题

Are you willing to submit a PR?

JNSimba commented 1 year ago

You can try 2.4.0

ByteInvoker commented 1 year ago

You can try 2.4.0

2.4.0依然有这个问题

MaoHJ-Official commented 1 year ago

Please refer to this FAQ, https://debezium.io/documentation/faq/#what_is_causing_intermittent_eventdatadeserializationexceptions_with_the_mysql_connector

It is speculated to be caused by a network malfunction.

komiblog commented 9 months ago

Same problem

ruanhang1993 commented 9 months ago

Considering collaboration with developers around the world, please re-create your issue in English on Apache Jira under project Flink with component tag Flink CDC. Thank you!

为了方便各个国家的贡献者交流，请在 Apache Jira 的 Flink 项目下重新用英文创建问题，同时在问题上将 Component 标注为 Flink CDC。谢谢！

njalan commented 1 month ago

这个问题解决了吗？我遇到了同样的问题。 用的是cdc 3.2