Uploaded image for project: 'Debezium'
  1. Debezium
  2. DBZ-4217

MySQL connector crashes parsing DATETIME

    XMLWordPrintable

Details

    • Bug
    • Resolution: Unresolved
    • Major
    • under-triaging
    • None
    • mysql-connector
    • None
    • False
    • False

    Description

      Has similarities with DBZ-4032

       

      When triggering an adhoc incremental snapshot, the MySQL connector crashes with the following stack trace

      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:42) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.handleEvent(MySqlStreamingChangeEventSource.java:366) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.lambda$execute$25(MySqlStreamingChangeEventSource.java:855) at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1125) at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:973) at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:599) at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:857) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: io.debezium.DebeziumException: Error processing binlog event ... 7 more Caused by: org.apache.kafka.connect.errors.ConnectException: Error while processing event at offset {transaction_id=null, ts_sec=1635434641, file=mysql-bin.000117, pos=78378556, incremental_snapshot_maximum_key=aced000570, gtids=3786cf53-f86d-11eb-afe2-42010a3c7032:1-7415958, row=1, server_id=2906499770, event=2, incremental_snapshot_collections=db.newsletter_configuration, incremental_snapshot_primary_key=aced000570} at io.debezium.pipeline.EventDispatcher.dispatchDataChangeEvent(EventDispatcher.java:255) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.lambda$handleInsert$4(MySqlStreamingChangeEventSource.java:688) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.handleChange(MySqlStreamingChangeEventSource.java:745) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.handleInsert(MySqlStreamingChangeEventSource.java:686) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.lambda$execute$16(MySqlStreamingChangeEventSource.java:831) at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.handleEvent(MySqlStreamingChangeEventSource.java:349) ... 6 more Caused by: java.lang.RuntimeException: Invalid length when read MySQL DATETIME value. BIN_LEN_DATETIME is 19 at io.debezium.connector.mysql.MysqlBinaryProtocolFieldReader.readTimestampField(MysqlBinaryProtocolFieldReader.java:101) at io.debezium.connector.mysql.AbstractMysqlFieldReader.readField(AbstractMysqlFieldReader.java:39) at io.debezium.connector.mysql.MySqlConnection.getColumnValue(MySqlConnection.java:595) at io.debezium.jdbc.JdbcConnection.rowToArray(JdbcConnection.java:1484) at io.debezium.pipeline.source.snapshot.incremental.AbstractIncrementalSnapshotChangeEventSource.lambda$readChunk$0(AbstractIncrementalSnapshotChangeEventSource.java:232) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:645) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:513) at io.debezium.pipeline.source.snapshot.incremental.AbstractIncrementalSnapshotChangeEventSource.readChunk(AbstractIncrementalSnapshotChangeEventSource.java:228) at io.debezium.pipeline.source.snapshot.incremental.AbstractIncrementalSnapshotChangeEventSource.addDataCollectionNamesToSnapshot(AbstractIncrementalSnapshotChangeEventSource.java:287) at io.debezium.pipeline.signal.ExecuteSnapshot.arrived(ExecuteSnapshot.java:56) at io.debezium.pipeline.signal.Signal.process(Signal.java:140) at io.debezium.pipeline.signal.Signal.process(Signal.java:184) at io.debezium.pipeline.EventDispatcher$2.changeRecord(EventDispatcher.java:229) at io.debezium.relational.RelationalChangeRecordEmitter.emitCreateRecord(RelationalChangeRecordEmitter.java:78) at io.debezium.relational.RelationalChangeRecordEmitter.emitChangeRecords(RelationalChangeRecordEmitter.java:46) at io.debezium.pipeline.EventDispatcher.dispatchDataChangeEvent(EventDispatcher.java:218) ... 11 more
      

      Contrary to DBZ-4032the invalid length is 19 not 0

      Steps to reproduce:

      MySQL version:  8.0.18-google

      Debezium MySQL version: 1.7

      Table DDL:
      **

      CREATE TABLE `newsletter_configuration` (
        `id` int(11) NOT NULL AUTO_INCREMENT,
        `name` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
        `lang` varchar(5) COLLATE utf8_unicode_ci NOT NULL,
        `recipient_email_addresses` longtext COLLATE utf8_unicode_ci NOT NULL COMMENT '(DC2Type:json_array)',
        `shipper_organization_id` int(11) NOT NULL,
        `carrier_organization_id` int(11) NOT NULL,
        `created_at` datetime DEFAULT NULL COMMENT '(DC2Type:datetime_immutable)',
        `updated_at` datetime DEFAULT NULL COMMENT '(DC2Type:datetime_immutable)',
        PRIMARY KEY (`id`)
      ) ENGINE=InnoDB AUTO_INCREMENT=3 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
      

      Sample Data:
      **

      INSERT INTO newsletter_configuration (name,lang,recipient_email_addresses,shipper_organization_id,carrier_organization_id,created_at,updated_at) VALUES     ('Newsletter test 1','en','["test@test.com"]',1839,1841,'2021-10-28 11:11:50','2021-10-28 14:58:30');
      

      Related Connector Config:
      **

      "event.deserialization.failure.handling.mode":"warn"
      "include.schema.changes":"true"
      "signal.data.collection":"db.debezium_signal"
      "snapshot.locking.mode":"none"
      "snapshot.fetch.size":"10000"
      "snapshot.mode":"schema_only"
      "table.include.list":"db.debezium_signal,db.newsletter_configuration"

      Triggering Snapshot:

      Snapshot was triggered with the signaling table mechanism

      INSERT INTO debezium_signal (id,`type`,`data`) VALUES     ('13','execute-snapshot','{"data-collections": ["db.newsletter_configuration"], "type": "INCREMENTAL"}');
      

      PS: I tried to use the newly-introduced signal.kafka.topic feature, got the same behavior.

       

      Important observation:

      The issues happens only when "snapshot.fetch.size" config is set. If I remove this config from the connector configs, the snapshot will work correctly.

      Attachments

        Issue Links

          Activity

            People

              ccranfor@redhat.com Chris Cranford
              omar.ghalawinji@gmail.com Omar Ghalawinji (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated: