zendesk / maxwell

Maxwell's daemon, a mysql-to-json kafka producer
https://maxwells-daemon.io/
Other
4.01k stars 1.01k forks source link

Failed to deserialize data of EventHeaderV4 #2067

Open hongshaoyang opened 10 months ago

hongshaoyang commented 10 months ago

Since a few days we have a lot of errors like this one in our logs :

02:06:50,268 WARN  BinlogConnectorLifecycleListener - Communication failure.
com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4{timestamp=1701306405000, eventType=EXT_UPDATE_ROWS, serverId=10800226, headerLength=19, dataLength=1358131, nextPosition=631661181, flags=0}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:300) ~[mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:223) ~[mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:954) [mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:581) [mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:857) [mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: java.io.EOFException
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:190) ~[mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at java.io.InputStream.read(InputStream.java:170) ~[?:1.8.0_222]
    at java.io.InputStream.skip(InputStream.java:224) ~[?:1.8.0_222]
    at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.skipToTheEndOfTheBlock(ByteArrayInputStream.java:216) ~[mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:296) ~[mysql-binlog-connector-java-0.20.0.jar:0.20.0]
    ... 5 more
02:06:50,268 INFO  BinlogConnectorLifecycleListener - Binlog disconnected.
02:06:50,406 WARN  BinlogConnectorReplicator - replicator stopped at position: 5aaf32aa-bc81-11e8-acdd-42010a50000d:1-42,807e7be2-6130-ee16-655f-c99b53c466f6:1-396747422,8a008e83-bd27-ee17-623e-88435fc1375f:1-276304239,ba9ae991-f49b-11ed-b33c-0242ac120002:1-657755188,d0e8bbff-9cdc-11e9-8cde-42010a500021:1-2134354217 -- restarting
02:06:50,496 INFO  BinaryLogClient - Connected to 10.80.0.226:6333 at 5aaf32aa-bc81-11e8-acdd-42010a50000d:1-42,807e7be2-6130-ee16-655f-c99b53c466f6:1-396747422,8a008e83-bd27-ee17-623e-88435fc1375f:1-276304239,ba9ae991-f49b-11ed-b33c-0242ac120002:1-657755188,d0e8bbff-9cdc-11e9-8cde-42010a500021:1-2134354217 (sid:1082294, cid:152006202)
02:06:50,496 INFO  BinlogConnectorLifecycleListener - Binlog connected.
hongshaoyang commented 10 months ago

We are using GTID based replication (gtid_mode=true) so I cannot find the corresponding binlog event

hongshaoyang commented 10 months ago

Marking this as related to #1432

osheroff commented 10 months ago

does maxwell resume normally after the error? I suspect there's a network issue;

Caused by: java.io.EOFException

usually means "somehow the network connection got closed".

It's also possible that your mysql server decided to close the connection. might check its logs

Job-madi commented 6 months ago

Hey @osheroff , we are running Maxwell in production and are facing this issue more often lately. Maxwell version: 1.41.0 MySQL: Percona MySQL 5.7.34-37

84100931 [WARN] BinlogConnectorReplicator: replicator stopped at position: mysql-bin.132564:349963810 -- restarting

84100940 [WARN] BinlogConnectorReplicator: communications failure in binlog:

com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4{timestamp=1710814071000, eventType=EXT_UPDATE_ROWS, serverId=1, headerLength=19, dataLength=217, nextPosition=349964134, flags=0}

        at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:341) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:244) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1051) [mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:631) [mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:932) [mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at java.lang.Thread.run(Thread.java:829) [?:?]

Caused by: java.io.EOFException: Failed to read remaining 5 of 5 bytes from position 880. Block length: 0. Initial block length: 213.

        at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.fill(ByteArrayInputStream.java:115) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.read(ByteArrayInputStream.java:105) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.AbstractRowsEventDataDeserializer.deserializeDatetimeV2(AbstractRowsEventDataDeserializer.java:361) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.AbstractRowsEventDataDeserializer.deserializeCell(AbstractRowsEventDataDeserializer.java:183) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.AbstractRowsEventDataDeserializer.deserializeRow(AbstractRowsEventDataDeserializer.java:143) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.UpdateRowsEventDataDeserializer.deserializeRows(UpdateRowsEventDataDeserializer.java:71) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.UpdateRowsEventDataDeserializer.deserialize(UpdateRowsEventDataDeserializer.java:58) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.UpdateRowsEventDataDeserializer.deserialize(UpdateRowsEventDataDeserializer.java:33) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:335) ~[mysql-binlog-connector-java-0.27.4.jar:0.27.4]
        ... 5 more

84101040 [WARN] BinlogConnectorReplicator: replicator stopped at position: mysql-bin.132564:349963810 -- restarting