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

long overflow for Time data type on MySQL database using MariaDB JDBC driver

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Not a Bug
    • Icon: Major Major
    • None
    • 2.6.1.Final
    • debezium-connector-mysql
    • None
    • True
    • None
    • False

      In order to make your issue reports as actionable as possible, please provide the following information, depending on the issue type.

      Bug report

      For bug reports, provide this information, please:

       

      What Debezium connector do you use and what version?

      2.6.1 Final

      What is the connector configuration?

      connector.class = io.debezium.connector.mysql.MySqlConnector
include.schema.changes = false
schema.history.internal.etcd.key = ********
database.jdbc.driver = org.mariadb.jdbc.Driver
schema.history.internal.etcd.ssl.keyStorePassword = ********
poll.interval.ms = 500
schema.history.internal.etcd.ssl.keyStore = file:src/main/resources/sec/etcd_v2.jks
errors.retry.delay.initial.ms = 300
snapshot.fetch.size = 500
key.converter = org.apache.kafka.connect.json.JsonConverter
etcd.ssl.keyPassword = ********
instance.id = ********
database.user = ********
offset.storage = ********
schema.history.internal.etcd.ssl.keyPassword = ********
heartbeat.interval.ms = 300000
database.protocol = jdbc:mariadb
schema.history.internal.etcd.endpoints = [http://127.0.0.1:2379]
errors.max.retries = 0
database.password = ********
name = 94d85000-8232-4bdf-a400-acb00abfd2f9
max.batch.size = 500
skipped.operations = t
snapshot.mode = when_needed
connect.timeout.ms = 60000
max.queue.size = 1500
database.vendor = mysql
offset.storage.etcd.key = ********
schema.history.internal.store.only.captured.tables.ddl = true
schema.history.internal.store.only.captured.databases.ddl = true
tombstones.on.delete = false
topic.prefix = 94d85000-8232-4bdf-a400-acb00abfd2f9
decimal.handling.mode = string
offset.storage.file.filename =
include.schema.comments = false
etcd.endpoints = [http://127.0.0.1:2379]
value.converter = org.apache.kafka.connect.json.JsonConverter
database.server.id = 505952925684608955
etcd.ssl.keyStore = file:src/main/resources/sec/etcd_v2.jks
offset.flush.timeout.ms = 60000
errors.retry.delay.max.ms = 10000
etcd.ssl.keyStorePassword = ********
database.port = ********
offset.flush.interval.ms = 5000
schema.history.internal = ********
database.hostname = ********
schema.history.internal.etcd.version = v3
table.include.list = fdi_test.table_all_support_type
include.query = false
etcd.version = v3

      What is the captured database version and mode of deployment?

      (E.g. on-premises, with a specific cloud provider, etc.)

      <Your answer>

      What behavior do you expect?

      <Your answer>

      What behavior do you see?

      when doing snapshot

       WARN  [Loggings.java:logWarningAndTraceRecord:30] - Failed to properly convert data value for 'fdi_test.table_all_numeric_datetime.time_col' of type TIME
java.lang.ArithmeticException: long overflow
    at java.base/java.lang.Math.multiplyExact(Math.java:1004)
    at java.base/java.time.Duration.toNanos(Duration.java:1250)
    at .lambda$convertDurationToMicroseconds$29(MySqlValueConverters.java:878)
    at io.debezium.jdbc.JdbcValueConverters.convertValue(JdbcValueConverters.java:1335)
    at .convertDurationToMicroseconds(MySqlValueConverters.java:875)
    at .lambda$converter$15(MySqlValueConverters.java:346)
    at .lambda$createValueGenerator$5(TableSchemaBuilder.java:297)
    at io.debezium.relational.TableSchema.valueFromColumnData(TableSchema.java:141)
    at io.debezium.relational.RelationalChangeRecordEmitter.emitReadRecord(RelationalChangeRecordEmitter.java:87)
    at io.debezium.relational.RelationalChangeRecordEmitter.emitChangeRecords(RelationalChangeRecordEmitter.java:50)
    at io.debezium.pipeline.EventDispatcher.dispatchSnapshotEvent(EventDispatcher.java:214)
    at io.debezium.relational.RelationalSnapshotChangeEventSource.doCreateDataEventsForTable(RelationalSnapshotChangeEventSource.java:625)
    at io.debezium.relational.RelationalSnapshotChangeEventSource.lambda$createDataEventsForTableCallable$7(RelationalSnapshotChangeEventSource.java:559)
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
 TRACE io.debezium.util.Loggings[Loggings.java:logWarningAndTraceRecord:31] - Source of warning is record '[1, 1, 1, 1, 1.0, 1.0, 1, 1.00, 2024-10-10 10:00:00.0, 2024-10-10 10:00:00.0, 2024-01-01, 2024-10-10, PT-2071628614H-48M-48.101314035S]'
 DEBUG [Loggings.java:logDebugAndTraceRecord:44] - Failed to properly convert data value for 'fdi_test.table_all_numeric_datetime.time_col' of type TIME
java.lang.ArithmeticException: long overflow
    at java.base/java.lang.Math.multiplyExact(Math.java:1004)
    at java.base/java.time.Duration.toNanos(Duration.java:1250)
    at .lambda$convertDurationToMicroseconds$29(MySqlValueConverters.java:878)
    at io.debezium.jdbc.JdbcValueConverters.convertValue(JdbcValueConverters.java:1335)
    at .convertDurationToMicroseconds(MySqlValueConverters.java:875)
    at .lambda$converter$15(MySqlValueConverters.java:346)
    at .lambda$createValueGenerator$5(TableSchemaBuilder.java:297)
    at io.debezium.relational.TableSchema.valueFromColumnData(TableSchema.java:141)
    at io.debezium.relational.RelationalChangeRecordEmitter.emitReadRecord(RelationalChangeRecordEmitter.java:87)
    at io.debezium.relational.RelationalChangeRecordEmitter.emitChangeRecords(RelationalChangeRecordEmitter.java:50)
    at io.debezium.pipeline.EventDispatcher.dispatchSnapshotEvent(EventDispatcher.java:214)
    at io.debezium.relational.RelationalSnapshotChangeEventSource.doCreateDataEventsForTable(RelationalSnapshotChangeEventSource.java:625)
    at io.debezium.relational.RelationalSnapshotChangeEventSource.lambda$createDataEventsForTableCallable$7(RelationalSnapshotChangeEventSource.java:559)
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
 TRACE io.debezium.util.Loggings[Loggings.java:logDebugAndTraceRecord:45] - Source of debug is record '[1, 1, 1, 1, 1.0, 1.0, 1, 1.00, 2024-10-10 10:00:00.0, 2024-10-10 10:00:00.0, 2024-01-01, 2024-10-10, PT-2071628614H-48M-48.101314035S]'

       
      inserted a new record for streaming

       TRACE [MySqlStreamingChangeEventSource.java:logEvent:1033] - Received event: Event\{header=EventHeaderV4{timestamp=1722372190000, eventType=XID, serverId=123, headerLength=19, dataLength=12, nextPosition=596337897, flags=0}, data=XidEventData\{xid=680417063}}
 TRACE [MySqlStreamingChangeEventSource.java:onEvent:225] - Current milliseconds behind source: 295740 ms
 TRACE [MySqlStreamingChangeEventSource.java:logEvent:1033] - Received event: Event\{header=EventHeaderV4{timestamp=1722372234000, eventType=GTID, serverId=123, headerLength=19, dataLength=60, nextPosition=596337976, flags=0}, data=GtidEventData\{flags=0, gtid='bdb89c44-8841-11ee-b7e9-0242ac110010:4737977', last_committed='606484', sequence_number='606485', immediate_commit_timestamp='1722372234191164', original_commit_timestamp='1722372234191164', transaction_length='743', immediate_server_version='80018', original_server_version='80018'}}
 TRACE [MySqlStreamingChangeEventSource.java:onEvent:225] - Current milliseconds behind source: 295740 ms
 TRACE [MySqlStreamingChangeEventSource.java:logEvent:1033] - Received event: Event\{header=EventHeaderV4{timestamp=1722372234000, eventType=QUERY, serverId=123, headerLength=19, dataLength=60, nextPosition=596338055, flags=8}, data=QueryEventData\{threadId=5390508, executionTime=0, errorCode=0, database='', sql='BEGIN'}}
 TRACE [MySqlStreamingChangeEventSource.java:ignoreEvent:250] - Ignoring event due to missing handler: Event\{header=EventHeaderV4{timestamp=1722372234000, eventType=ROWS_QUERY, serverId=123, headerLength=19, dataLength=350, nextPosition=596338424, flags=128}, data=RowsQueryEventData{query='/* ApplicationName=DBeaver 22.3.2 - Main */ INSERT INTO fdi_test.table_all_numeric_datetime (int_col,big_int_col,tiny_int_col,medium_int_col,float_col,double_col,small_int_col,decimal_col,datetime_col,timestamp_col,year_col,date_col,time_col)
','2024-10-10 10:00:00',2024,'2024-10-10','10:00:00')'}}
 TRACE [MySqlStreamingChangeEventSource.java:onEvent:225] - Current milliseconds behind source: 295741 ms
 TRACE [MySqlStreamingChangeEventSource.java:logEvent:1033] - Received event: Event\{header=EventHeaderV4{timestamp=1722372234000, eventType=ROWS_QUERY, serverId=123, headerLength=19, dataLength=350, nextPosition=596338424, flags=128}, data=RowsQueryEventData{query='/* ApplicationName=DBeaver 22.3.2 - Main */ INSERT INTO fdi_test.table_all_numeric_datetime (int_col,big_int_col,tiny_int_col,medium_int_col,float_col,double_col,small_int_col,decimal_col,datetime_col,timestamp_col,year_col,date_col,time_col)
    VALUES (2,1,2,2,2.0,2.0,2,2,'2024-10-10 10:00:00','2024-10-10 10:00:00',2024,'2024-10-10','10:00:00')'}}
 DEBUG [ChangeEventQueue.java:poll:277] - checking for more records...
 DEBUG [ChangeEventQueue.java:poll:258] - polling records...
 DEBUG [ChangeEventQueue.java:poll:269] - no records available or batch size not reached yet, sleeping a bit...
 DEBUG [MySqlStreamingChangeEventSource.java:onCommunicationFailure:1128] - A communication failure event arrived
com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4\{timestamp=1722372234000, eventType=TABLE_MAP, serverId=123, headerLength=19, dataLength=77, nextPosition=596338520, flags=0}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:343)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeTableMapEventData(EventDeserializer.java:315)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:239)
    at io.debezium.connector.mysql.strategy.AbstractBinaryLogClientConfigurator$1.nextEvent(AbstractBinaryLogClientConfigurator.java:110)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1068)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:648)
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:949)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.io.EOFException: Failed to read remaining 1 of 2 bytes from position 3. Block length: 0. Initial block length: 1.
    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.event.deserialization.TableMapEventMetadataDeserializer.readBooleanList(TableMapEventMetadataDeserializer.java:144)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventMetadataDeserializer.deserialize(TableMapEventMetadataDeserializer.java:90)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventDataDeserializer.deserialize(TableMapEventDataDeserializer.java:49)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventDataDeserializer.deserialize(TableMapEventDataDeserializer.java:29)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:337)
    ... 7 common frames omitted
 ERROR [MySqlStreamingChangeEventSource.java:logStreamingSourceState:1047] - Error during binlog processing. Last offset stored = \{file=mysql-bin.000050, pos=596337976, gtids=bdb89c44-8841-11ee-b7e9-0242ac110010:1-4737976, server_id=123, event=2}, binlog reader near position = mysql-bin.000050/596338424
 INFO  [BinaryLogClient.java:run:878] - threadExecutor is shut down, terminating keepalive thread
 DEBUG [ChangeEventQueue.java:poll:277] - checking for more records...
 DEBUG [ChangeEventQueue.java:poll:258] - polling records...
 DEBUG [ChangeEventQueue.java:poll:269] - no records available or batch size not reached yet, sleeping a bit...
 ERROR io.debezium.pipeline.ErrorHandler[ErrorHandler.java:setProducerThrowable:52] - Producer failure
io.debezium.DebeziumException: Failed to deserialize data of EventHeaderV4\{timestamp=1722372234000, eventType=TABLE_MAP, serverId=123, headerLength=19, dataLength=77, nextPosition=596338520, flags=0}
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource.wrap(MySqlStreamingChangeEventSource.java:1092)
    at io.debezium.connector.mysql.MySqlStreamingChangeEventSource$ReaderThreadLifecycleListener.onCommunicationFailure(MySqlStreamingChangeEventSource.java:1137)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1096)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:648)
    at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:949)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: com.github.shyiko.mysql.binlog.event.deserialization.EventDataDeserializationException: Failed to deserialize data of EventHeaderV4\{timestamp=1722372234000, eventType=TABLE_MAP, serverId=123, headerLength=19, dataLength=77, nextPosition=596338520, flags=0}
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:343)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeTableMapEventData(EventDeserializer.java:315)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:239)
    at io.debezium.connector.mysql.strategy.AbstractBinaryLogClientConfigurator$1.nextEvent(AbstractBinaryLogClientConfigurator.java:110)
    at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:1068)
    ... 3 common frames omitted
Caused by: java.io.EOFException: Failed to read remaining 1 of 2 bytes from position 3. Block length: 0. Initial block length: 1.
    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.event.deserialization.TableMapEventMetadataDeserializer.readBooleanList(TableMapEventMetadataDeserializer.java:144)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventMetadataDeserializer.deserialize(TableMapEventMetadataDeserializer.java:90)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventDataDeserializer.deserialize(TableMapEventDataDeserializer.java:49)
    at com.github.shyiko.mysql.binlog.event.deserialization.TableMapEventDataDeserializer.deserialize(TableMapEventDataDeserializer.java:29)
    at com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:337)
    ... 7 common frames omitted

      Do you see the same behaviour using the latest released Debezium version?

      (Ideally, also verify with latest Alpha/Beta/CR version)

      <Your answer>

      Do you have the connector logs, ideally from start till finish?

       
      Please see snapshot.txt and streaming.txt

      How to reproduce the issue using our tutorial deployment?

       

      create a table on MySQL database

      CREATE TABLE `table_all_numeric_datetime` (
  `int_col` int(11) NOT NULL,
  `big_int_col` bigint(20) DEFAULT NULL,
  `tiny_int_col` tinyint(4) DEFAULT NULL,
  `medium_int_col` mediumint(9) DEFAULT NULL,
  `float_col` float DEFAULT NULL,
  `double_col` double DEFAULT NULL,
  `small_int_col` smallint(6) DEFAULT NULL,
  `decimal_col` decimal(10,2) DEFAULT NULL,
  `datetime_col` datetime DEFAULT NULL,
  `timestamp_col` timestamp NULL DEFAULT NULL,
  `year_col` year(4) DEFAULT NULL,
  `date_col` date DEFAULT NULL,
  `time_col` time DEFAULT NULL,
  PRIMARY KEY (`int_col`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin;

      create a MySQL connector but changed the jdbc driver to MariaDB driver

      database.jdbc.driver = org.mariadb.jdbc.Driver
database.protocol = jdbc:mariadb

      Feature request or enhancement

      For feature requests or enhancements, provide this information, please:

      Which use case/requirement will be addressed by the proposed feature?

      <Your answer>

      Implementation ideas (optional)

      <Your answer>

        1. snapshot.txt
          12 kB
        2. streaming.txt
          8 kB

              ccranfor@redhat.com Chris Cranford
              wing2005hk Wing Wing (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: