-
Bug
-
Resolution: Done
-
Minor
-
1.6.0.Final
-
None
-
False
-
False
-
Undefined
-
I received the following error during snapshotting the commute_report table due to TIME columns of the table, "work_on_time" and "work_off_time". When checking the data from the database attached below, it seems okay.
related code:
If you want to ask me some specific query results, feel free to ask me.
Thanks!
Error Log
2021-07-19 07:32:02,507 INFO MySQL|schedule_server|snapshot Exporting data from table 'schedule.commute_report' (11 of 74 tables) [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-07-19 07:32:02,507 INFO MySQL|schedule_server|snapshot Exporting data from table 'schedule.commute_report' (11 of 74 tables) [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-07-19 07:32:02,507 INFO MySQL|schedule_server|snapshot For table 'schedule.commute_report' using select statement: 'SELECT * FROM `schedule`.`commute_report`' [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-07-19 07:32:13,101 INFO MySQL|schedule_server|snapshot Snapshot - Final stage [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
2021-07-19 07:32:13,101 ERROR MySQL|schedule_server|snapshot Producer failure [io.debezium.pipeline.ErrorHandler]io.debezium.DebeziumException: java.lang.RuntimeException: Invalid length when read MySQL TIME value. BIN_LEN_TIME is 0
at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:78)
at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:113)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: Invalid length when read MySQL TIME value. BIN_LEN_TIME is 0
at io.debezium.connector.mysql.MysqlBinaryProtocolFieldReader.readTimeField(MysqlBinaryProtocolFieldReader.java:38)
at io.debezium.connector.mysql.AbstractMysqlFieldReader.readField(AbstractMysqlFieldReader.java:30)
at io.debezium.connector.mysql.MySqlConnection.getColumnValue(MySqlConnection.java:571)
at io.debezium.jdbc.JdbcConnection.rowToArray(JdbcConnection.java:1470)
at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEventsForTable(RelationalSnapshotChangeEventSource.java:355)
at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEvents(RelationalSnapshotChangeEventSource.java:306)
at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:136)
at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:69) ... 6 more
2021-07-19 07:32:13,188 INFO || The task will send records to topic 'schedule_topic_commute_report' for the first time. Checking whether topic exists [org.apache.kafka.connect.runtime.WorkerSourceTask]
2021-07-19 07:32:13,190 INFO || Topic 'schedule_topic_commute_report' already exists. [org.apache.kafka.connect.runtime.WorkerSourceTask]
2021-07-19 07:32:13,206 INFO || WorkerSourceTask{id=schedule-0} Committing offsets [org.apache.kafka.connect.runtime.WorkerSourceTask]
2021-07-19 07:32:13,206 INFO || WorkerSourceTask{id=schedule-0} flushing 172 outstanding messages for offset commit [org.apache.kafka.connect.runtime.WorkerSourceTask]
2021-07-19 07:32:13,226 INFO || WorkerSourceTask{id=schedule-0} Finished commitOffsets successfully in 20 ms [org.apache.kafka.connect.runtime.WorkerSourceTask]
2021-07-19 07:32:13,226 ERROR || WorkerSourceTask{id=schedule-0} Task threw an uncaught and unrecoverable exception. Task is being killed and will not recover until manually restarted [org.apache.kafka.connect.runtime.WorkerTask]
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.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:130)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)Caused by: io.debezium.DebeziumException: java.lang.RuntimeException: Invalid length when read MySQL TIME value. BIN_LEN_TIME is 0
at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:78)
at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:113) ... 5 more
Caused by: java.lang.RuntimeException: Invalid length when read MySQL TIME value. BIN_LEN_TIME is 0
at io.debezium.connector.mysql.MysqlBinaryProtocolFieldReader.readTimeField(MysqlBinaryProtocolFieldReader.java:38)
at io.debezium.connector.mysql.AbstractMysqlFieldReader.readField(AbstractMysqlFieldReader.java:30)
at io.debezium.connector.mysql.MySqlConnection.getColumnValue(MySqlConnection.java:571)
at io.debezium.jdbc.JdbcConnection.rowToArray(JdbcConnection.java:1470)
at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEventsForTable(RelationalSnapshotChangeEventSource.java:355)
at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEvents(RelationalSnapshotChangeEventSource.java:306)
at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:136)
at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:69) ... 6 more
2021-07-19 07:32:13,227 INFO || Stopping down connector [io.debezium.connector.common.BaseSourceTask]
2021-07-19 07:32:13,229 INFO || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2021-07-19 07:32:13,229 INFO || [Producer clientId=schedule_server-dbhistory] Closing the Kafka producer with timeoutMillis = 30000 ms. [org.apache.kafka.clients.producer.KafkaProducer]
2021-07-19 07:32:13,231 INFO || Metrics scheduler closed [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,231 INFO || Closing reporter org.apache.kafka.common.metrics.JmxReporter [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,231 INFO || Metrics reporters closed [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,232 INFO || App info kafka.producer for schedule_server-dbhistory unregistered [org.apache.kafka.common.utils.AppInfoParser]
2021-07-19 07:32:13,232 INFO || [Producer clientId=connector-producer-schedule-0] Closing the Kafka producer with timeoutMillis = 30000 ms. [org.apache.kafka.clients.producer.KafkaProducer]
2021-07-19 07:32:13,233 INFO || Metrics scheduler closed [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,234 INFO || Closing reporter org.apache.kafka.common.metrics.JmxReporter [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,234 INFO || Metrics reporters closed [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,234 INFO || App info kafka.producer for connector-producer-schedule-0 unregistered [org.apache.kafka.common.utils.AppInfoParser]
2021-07-19 07:32:13,234 INFO || App info kafka.admin.client for connector-adminclient-schedule-0 unregistered [org.apache.kafka.common.utils.AppInfoParser]
2021-07-19 07:32:13,235 INFO || Metrics scheduler closed [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,236 INFO || Closing reporter org.apache.kafka.common.metrics.JmxReporter [org.apache.kafka.common.metrics.Metrics]
2021-07-19 07:32:13,236 INFO || Metrics reporters closed [org.apache.kafka.common.metrics.Metrics
Data Inspection
MySQL [schedule]> select version(); +------------+ | version() | +------------+ | 5.7.28-log | +------------+ MySQL [schedule]> select count(*) from commute_report; +----------+ | count(*) | +----------+ | 2495883 | +----------+ 1 row in set (0.46 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) = 8; +----------+ | count(*) | +----------+ | 391787 | +----------+ 1 row in set (0.94 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) is null; +----------+ | count(*) | +----------+ | 2104096 | +----------+ 1 row in set (1.02 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) = 8; +----------+ | count(*) | +----------+ | 312928 | +----------+ 1 row in set (0.90 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) is null; +----------+ | count(*) | +----------+ | 2182988 | +----------+ 1 row in set (0.92 sec) MySQL [schedule]> select count(*) from commute_report; +----------+ | count(*) | +----------+ | 2495974 | +----------+ 1 row in set (0.46 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) < 8; +----------+ | count(*) | +----------+ | 0 | +----------+ 1 row in set (1.07 sec) MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) < 8; +----------+ | count(*) | +----------+ | 0 | +----------+ MySQL [******]> select distinct(length(work_on_time)) from commute_report; +------------------------+ | (length(work_on_time)) | +------------------------+ | 8 | | NULL | +------------------------+ MySQL [******]> describe commute_report; +-------------------+--------------+------+-----+---------+----------------+ | Field | Type | Null | Key | Default | Extra | +-------------------+--------------+------+-----+---------+----------------+ | seq | bigint(20) | NO | PRI | NULL | auto_increment | | work_on_time | time | YES | | NULL | | | work_off_time | time | YES | | NULL | |
MySQL [schedule]> select count(*) from commute_report; +----------+ | count(*) | +----------+ | 2495883 | +----------+ 1 row in set (0.46 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) = 8; +----------+ | count(*) | +----------+ | 391787 | +----------+ 1 row in set (0.94 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) is null; +----------+ | count(*) | +----------+ | 2104096 | +----------+ 1 row in set (1.02 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) = 8; +----------+ | count(*) | +----------+ | 312928 | +----------+ 1 row in set (0.90 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) is null; +----------+ | count(*) | +----------+ | 2182988 | +----------+ 1 row in set (0.92 sec)MySQL [schedule]> select count(*) from commute_report; +----------+ | count(*) | +----------+ | 2495974 | +----------+ 1 row in set (0.46 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_off_time) < 8; +----------+ | count(*) | +----------+ | 0 | +----------+ 1 row in set (1.07 sec)MySQL [schedule]> select count(*) from commute_report where char_length(work_on_time) < 8; +----------+ | count(*) | +----------+ | 0 | +----------+ MySQL [******]> select distinct(length(work_on_time)) from commute_report; +------------------------+ | (length(work_on_time)) | +------------------------+ | 8 | | NULL | +------------------------+ MySQL [******]> describe commute_report; +-------------------+--------------+------+-----+---------+----------------+ | Field | Type | Null | Key | Default | Extra | +-------------------+--------------+------+-----+---------+----------------+ | seq | bigint(20) | NO | PRI | NULL | auto_increment | | work_on_time | time | YES | | NULL | | | work_off_time | time | YES | | NULL |
Sample Data
MySQL [schedule]> select rand() as ord, seq, work_on_time, work_off_time from commute_report order by ord desc limit 100; +--------------------+---------+--------------+---------------+ | ord | seq | work_on_time | work_off_time | +--------------------+---------+--------------+---------------+ | 0.9999994337558741 | 545886 | NULL | NULL | | 0.9999993667006487 | 1512064 | NULL | NULL | | 0.9999992577359074 | 2172851 | NULL | NULL | | 0.9999973699450468 | 2461434 | NULL | NULL | | 0.9999968688935013 | 201800 | NULL | NULL | | 0.9999967161565988 | 1972245 | NULL | NULL | | 0.999995737336572 | 2136452 | NULL | NULL | | 0.9999952996149616 | 2150280 | NULL | NULL | | 0.9999949056655121 | 269791 | NULL | NULL | | 0.9999947967007707 | 2288736 | NULL | NULL | | 0.999992986209684 | 2282243 | NULL | NULL | | 0.9999929023906522 | 1422257 | 09:00:14 | 17:53:00 | | 0.9999925941228798 | 1865928 | 08:00:00 | 17:00:28 | | 0.9999910350888884 | 1940251 | NULL | NULL | | 0.9999909074976956 | 1173527 | NULL | NULL | | 0.999989660456767 | 1425295 | NULL | NULL | | 0.9999891240149635 | 1618891 | NULL | NULL | | 0.999989098869254 | 499540 | NULL | NULL | | 0.9999872110783935 | 2539554 | NULL | NULL | | 0.9999870853498458 | 315846 | NULL | NULL | | 0.9999869009479758 | 520259 | NULL | NULL | | 0.9999867752194281 | 48107 | NULL | NULL | | 0.9999867016449446 | 1076949 | NULL | NULL | | 0.999986582435655 | 1402073 | NULL | NULL | | 0.9999860813841094 | 2313398 | NULL | NULL | | 0.9999857777729498 | 76006 | NULL | NULL | | 0.9999856036156282 | 102674 | NULL | NULL | | 0.9999854611232741 | 1286372 | NULL | NULL | | 0.9999853335320813 | 456569 | NULL | NULL | | 0.9999849144369223 | 667185 | NULL | NULL | | 0.9999848641455032 | 1048404 | NULL | NULL | | 0.999984706751988 | 1755075 | NULL | NULL | | 0.9999842289835068 | 72423 | NULL | NULL | | 0.9999840781092495 | 587257 | NULL | NULL | | 0.9999840781092495 | 1351906 | NULL | NULL | | 0.9999840781092495 | 1684848 | NULL | NULL | | 0.9999830136075458 | 1451653 | 08:00:00 | 17:00:00 | | 0.9999829614534815 | 990496 | NULL | NULL | | 0.9999828776344497 | 2156267 | NULL | NULL | | 0.9999827370047408 | 1719500 | NULL | NULL | | 0.999982653185709 | 1606494 | NULL | NULL | | 0.9999825675040321 | 847672 | 08:53:56 | 18:01:37 | | 0.9999825190752581 | 1886804 | NULL | NULL | | 0.999982282519324 | 134005 | NULL | NULL | | 0.9999819975346159 | 1455372 | NULL | NULL | | 0.9999818047508428 | 1258161 | NULL | NULL | | 0.9999816389754244 | 1036274 | 08:48:04 | 18:05:00 | | 0.9999807421117841 | 2329483 | NULL | NULL | | 0.9999804887920436 | 670199 | NULL | NULL | | 0.9999798098578861 | 2252123 | NULL | NULL | | 0.9999792817979858 | 863066 | NULL | NULL | | 0.9999783113598621 | 1848779 | NULL | NULL | | 0.9999782340600883 | 1135668 | NULL | NULL | | 0.9999781167134438 | 931394 | 08:41:16 | NULL | | 0.9999778233468326 | 1047410 | 07:47:56 | 17:30:15 | | 0.9999770605936433 | 169871 | NULL | NULL | | 0.9999769013374828 | 2427366 | 13:43:41 | NULL | | 0.999976440332808 | 2109681 | NULL | NULL | | 0.9999763565137763 | 1275069 | NULL | NULL | | 0.9999762643128413 | 2136226 | NULL | NULL | | 0.9999756962060702 | 739433 | 08:58:58 | 20:43:16 | | 0.9999756524339092 | 2285353 | NULL | NULL | | 0.9999747322872046 | 1407888 | NULL | NULL | | 0.9999731732532132 | 2042979 | NULL | NULL | | 0.9999728798866019 | 301276 | 12:24:34 | NULL | | 0.99997270200399 | 273148 | NULL | NULL | | 0.9999725427478297 | 825897 | NULL | NULL | | 0.9999723350628953 | 1145578 | NULL | NULL | | 0.9999722996726375 | 1409130 | NULL | NULL | | 0.999972140416477 | 32886 | NULL | NULL | | 0.9999721152707675 | 1635839 | NULL | NULL | | 0.9999715806916092 | 2076315 | NULL | NULL | | 0.9999715220182869 | 690143 | NULL | NULL | | 0.9999708998948065 | 1421975 | 08:54:49 | 20:07:10 | | 0.9999707238748397 | 1548577 | NULL | NULL | | 0.9999704156070672 | 2188698 | NULL | NULL | | 0.9999702982604227 | 1874248 | NULL | NULL | | 0.9999702144413909 | 332017 | NULL | NULL | | 0.9999692337587189 | 959988 | NULL | NULL | | 0.9999691396951388 | 739216 | 08:53:54 | 18:11:54 | | 0.9999689152463981 | 938565 | NULL | NULL | | 0.9999685948714322 | 1220553 | 07:55:58 | 19:07:48 | | 0.9999685948714322 | 707103 | NULL | NULL | | 0.9999680602922738 | 2147874 | NULL | NULL | | 0.9999670777469567 | 947681 | NULL | NULL | | 0.9999663066118641 | 391139 | 07:50:17 | 17:32:12 | | 0.9999656965955772 | 1760107 | NULL | NULL | | 0.9999653762206113 | 1473565 | NULL | NULL | | 0.999965175054935 | 1537 | 09:00:00 | 18:00:00 | | 0.9999648565426141 | 1413898 | NULL | NULL | | 0.9999648062511951 | 1333371 | NULL | NULL | | 0.9999646889045506 | 368041 | NULL | NULL | | 0.9999637920409103 | 637028 | NULL | NULL | | 0.9999625114723691 | 1977670 | NULL | NULL | | 0.9999617971479537 | 727641 | NULL | NULL | | 0.9999616881832124 | 763863 | NULL | NULL | | 0.9999615121632456 | 1570595 | 09:53:26 | 19:02:14 | | 0.9999600471928344 | 847317 | NULL | NULL | | 0.999959475360773 | 1945339 | NULL | NULL | | 0.9999588802456473 | 478220 | NULL | NULL | +--------------------+---------+--------------+---------------+
