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

Debezium fails if a non-existing view with the same name as existing table is dropped

    XMLWordPrintable

    Details

    • Steps to Reproduce:
      Hide
      1. Grab the example setup for MySQL from the tutorial.
      2. Log in to the MySQL database.
      3. Execute the following statement:
        DROP VIEW IF EXISTS customers;
      4. Update an existing record:
        UPDATE customers set first_name='N' where id=1001;
      5. Observe the connector crash:
        connect_1    | 2020-10-22 00:07:14,840 INFO   MySQL|dbserver1|binlog  1 records sent during previous 00:00:37.639, last recorded offset: {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344}   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:33,184 INFO   ||  WorkerSourceTask{id=inventory-connector-0} Committing offsets   [org.apache.kafka.connect.runtime.WorkerSourceTask]
        connect_1    | 2020-10-22 00:07:33,186 INFO   ||  WorkerSourceTask{id=inventory-connector-0} flushing 0 outstanding messages for offset commit   [org.apache.kafka.connect.runtime.WorkerSourceTask]
        connect_1    | 2020-10-22 00:07:33,202 INFO   ||  WorkerSourceTask{id=inventory-connector-0} Finished commitOffsets successfully in 17 ms   [org.apache.kafka.connect.runtime.WorkerSourceTask]
        connect_1    | 2020-10-22 00:07:38,046 ERROR  MySQL|dbserver1|binlog  Encountered change event 'Event{header=EventHeaderV4{timestamp=1603325258000, eventType=TABLE_MAP, serverId=223344, headerLength=19, dataLength=47, nextPosition=530, flags=0}, data=TableMapEventData{tableId=228, database='inventory', table='customers', columnTypes=3, 15, 15, 15, columnMetadata=0, 255, 255, 255, columnNullability={}, eventMetadata=null}}' at offset {ts_sec=1603325258, file=mysql-bin.000003, pos=385, server_id=223344, event=1} for table inventory.customers whose schema isn't known to this connector. One possible cause is an incomplete database history topic. Take a new snapshot in this case.
        connect_1    | Use the mysqlbinlog tool to view the problematic event: mysqlbinlog --start-position=464 --stop-position=530 --verbose mysql-bin.000003   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,046 ERROR  MySQL|dbserver1|binlog  Error during binlog processing. Last offset stored = {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344}, binlog reader near position = mysql-bin.000003/464   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,047 ERROR  MySQL|dbserver1|binlog  Failed due to error: Error processing binlog event   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector
        connect_1    | 	at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230)
        connect_1    | 	at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:600)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1130)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:978)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:581)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:860)
        connect_1    | 	at java.base/java.lang.Thread.run(Thread.java:834)
        connect_1    | Caused by: org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.informAboutUnknownTableIfRequired(BinlogReader.java:858)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleUpdateTableMetadata(BinlogReader.java:832)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:583)
        connect_1    | 	... 5 more
        connect_1    | 2020-10-22 00:07:38,050 INFO   MySQL|dbserver1|binlog  Error processing binlog event, and propagating to Kafka Connect so it stops this connector. Future binlog events read before connector is shutdown will be ignored.   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,339 INFO   ||  WorkerSourceTask{id=inventory-connector-0} Committing offsets   [org.apache.kafka.connect.runtime.WorkerSourceTask]
        connect_1    | 2020-10-22 00:07:38,341 INFO   ||  WorkerSourceTask{id=inventory-connector-0} flushing 0 outstanding messages for offset commit   [org.apache.kafka.connect.runtime.WorkerSourceTask]
        connect_1    | 2020-10-22 00:07:38,341 ERROR  ||  WorkerSourceTask{id=inventory-connector-0} Task threw an uncaught and unrecoverable exception   [org.apache.kafka.connect.runtime.WorkerTask]
        connect_1    | org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector
        connect_1    | 	at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230)
        connect_1    | 	at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:600)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1130)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:978)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:581)
        connect_1    | 	at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:860)
        connect_1    | 	at java.base/java.lang.Thread.run(Thread.java:834)
        connect_1    | Caused by: org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.informAboutUnknownTableIfRequired(BinlogReader.java:858)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleUpdateTableMetadata(BinlogReader.java:832)
        connect_1    | 	at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:583)
        connect_1    | 	... 5 more
        connect_1    | 2020-10-22 00:07:38,342 ERROR  ||  WorkerSourceTask{id=inventory-connector-0} Task is being killed and will not recover until manually restarted   [org.apache.kafka.connect.runtime.WorkerTask]
        connect_1    | 2020-10-22 00:07:38,342 INFO   ||  Stopping down connector   [io.debezium.connector.common.BaseSourceTask]
        connect_1    | 2020-10-22 00:07:38,342 INFO   MySQL|dbserver1|task  Stopping MySQL connector task   [io.debezium.connector.mysql.MySqlConnectorTask]
        connect_1    | 2020-10-22 00:07:38,342 INFO   MySQL|dbserver1|task  ChainedReader: Stopping the binlog reader   [io.debezium.connector.mysql.ChainedReader]
        connect_1    | 2020-10-22 00:07:38,343 INFO   MySQL|dbserver1|task  Discarding 0 unsent record(s) due to the connector shutting down   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,344 INFO   MySQL|dbserver1|task  Discarding 0 unsent record(s) due to the connector shutting down   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,345 INFO   MySQL|dbserver1|binlog  Stopped reading binlog after 1 events, last recorded offset: {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344}   [io.debezium.connector.mysql.BinlogReader]
        connect_1    | 2020-10-22 00:07:38,345 INFO   MySQL|dbserver1|task  [Producer clientId=inventory-connector-dbhistory] Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms.   [org.apache.kafka.clients.producer.KafkaProducer]
        connect_1    | 2020-10-22 00:07:38,350 INFO   MySQL|dbserver1|task  Connector task finished all work and is now shutdown   [io.debezium.connector.mysql.MySqlConnectorTask]
        connect_1    | 2020-10-22 00:07:38,350 INFO   ||  [Producer clientId=connector-producer-inventory-connector-0] Closing the Kafka producer with timeoutMillis = 30000 ms.   [org.apache.kafka.clients.producer.KafkaProducer]
        

        The reason is that the DropViewParserListener doesn't respect the skipViews flag.

      Show
      Grab the example setup for MySQL from the tutorial. Log in to the MySQL database. Execute the following statement: DROP VIEW IF EXISTS customers; Update an existing record: UPDATE customers set first_name='N' where id=1001; Observe the connector crash: connect_1 | 2020-10-22 00:07:14,840 INFO MySQL|dbserver1|binlog 1 records sent during previous 00:00:37.639, last recorded offset: {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344} [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:33,184 INFO || WorkerSourceTask{id=inventory-connector-0} Committing offsets [org.apache.kafka.connect.runtime.WorkerSourceTask] connect_1 | 2020-10-22 00:07:33,186 INFO || WorkerSourceTask{id=inventory-connector-0} flushing 0 outstanding messages for offset commit [org.apache.kafka.connect.runtime.WorkerSourceTask] connect_1 | 2020-10-22 00:07:33,202 INFO || WorkerSourceTask{id=inventory-connector-0} Finished commitOffsets successfully in 17 ms [org.apache.kafka.connect.runtime.WorkerSourceTask] connect_1 | 2020-10-22 00:07:38,046 ERROR MySQL|dbserver1|binlog Encountered change event 'Event{header=EventHeaderV4{timestamp=1603325258000, eventType=TABLE_MAP, serverId=223344, headerLength=19, dataLength=47, nextPosition=530, flags=0}, data=TableMapEventData{tableId=228, database='inventory', table='customers', columnTypes=3, 15, 15, 15, columnMetadata=0, 255, 255, 255, columnNullability={}, eventMetadata=null}}' at offset {ts_sec=1603325258, file=mysql-bin.000003, pos=385, server_id=223344, event=1} for table inventory.customers whose schema isn't known to this connector. One possible cause is an incomplete database history topic. Take a new snapshot in this case. connect_1 | Use the mysqlbinlog tool to view the problematic event: mysqlbinlog --start-position=464 --stop-position=530 --verbose mysql-bin.000003 [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,046 ERROR MySQL|dbserver1|binlog Error during binlog processing. Last offset stored = {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344}, binlog reader near position = mysql-bin.000003/464 [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,047 ERROR MySQL|dbserver1|binlog Failed due to error: Error processing binlog event [io.debezium.connector.mysql.BinlogReader] connect_1 | org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector connect_1 | at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230) connect_1 | at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:600) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1130) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:978) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:581) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:860) connect_1 | at java.base/java.lang.Thread.run(Thread.java:834) connect_1 | Caused by: org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector connect_1 | at io.debezium.connector.mysql.BinlogReader.informAboutUnknownTableIfRequired(BinlogReader.java:858) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleUpdateTableMetadata(BinlogReader.java:832) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:583) connect_1 | ... 5 more connect_1 | 2020-10-22 00:07:38,050 INFO MySQL|dbserver1|binlog Error processing binlog event, and propagating to Kafka Connect so it stops this connector. Future binlog events read before connector is shutdown will be ignored. [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,339 INFO || WorkerSourceTask{id=inventory-connector-0} Committing offsets [org.apache.kafka.connect.runtime.WorkerSourceTask] connect_1 | 2020-10-22 00:07:38,341 INFO || WorkerSourceTask{id=inventory-connector-0} flushing 0 outstanding messages for offset commit [org.apache.kafka.connect.runtime.WorkerSourceTask] connect_1 | 2020-10-22 00:07:38,341 ERROR || WorkerSourceTask{id=inventory-connector-0} Task threw an uncaught and unrecoverable exception [org.apache.kafka.connect.runtime.WorkerTask] connect_1 | org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector connect_1 | at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230) connect_1 | at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:600) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.notifyEventListeners(BinaryLogClient.java:1130) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:978) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:581) connect_1 | at com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:860) connect_1 | at java.base/java.lang.Thread.run(Thread.java:834) connect_1 | Caused by: org.apache.kafka.connect.errors.ConnectException: Encountered change event for table inventory.customers whose schema isn't known to this connector connect_1 | at io.debezium.connector.mysql.BinlogReader.informAboutUnknownTableIfRequired(BinlogReader.java:858) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleUpdateTableMetadata(BinlogReader.java:832) connect_1 | at io.debezium.connector.mysql.BinlogReader.handleEvent(BinlogReader.java:583) connect_1 | ... 5 more connect_1 | 2020-10-22 00:07:38,342 ERROR || WorkerSourceTask{id=inventory-connector-0} Task is being killed and will not recover until manually restarted [org.apache.kafka.connect.runtime.WorkerTask] connect_1 | 2020-10-22 00:07:38,342 INFO || Stopping down connector [io.debezium.connector.common.BaseSourceTask] connect_1 | 2020-10-22 00:07:38,342 INFO MySQL|dbserver1|task Stopping MySQL connector task [io.debezium.connector.mysql.MySqlConnectorTask] connect_1 | 2020-10-22 00:07:38,342 INFO MySQL|dbserver1|task ChainedReader: Stopping the binlog reader [io.debezium.connector.mysql.ChainedReader] connect_1 | 2020-10-22 00:07:38,343 INFO MySQL|dbserver1|task Discarding 0 unsent record(s) due to the connector shutting down [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,344 INFO MySQL|dbserver1|task Discarding 0 unsent record(s) due to the connector shutting down [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,345 INFO MySQL|dbserver1|binlog Stopped reading binlog after 1 events, last recorded offset: {ts_sec=1603325234, file=mysql-bin.000003, pos=320, server_id=223344} [io.debezium.connector.mysql.BinlogReader] connect_1 | 2020-10-22 00:07:38,345 INFO MySQL|dbserver1|task [Producer clientId=inventory-connector-dbhistory] Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms. [org.apache.kafka.clients.producer.KafkaProducer] connect_1 | 2020-10-22 00:07:38,350 INFO MySQL|dbserver1|task Connector task finished all work and is now shutdown [io.debezium.connector.mysql.MySqlConnectorTask] connect_1 | 2020-10-22 00:07:38,350 INFO || [Producer clientId=connector-producer-inventory-connector-0] Closing the Kafka producer with timeoutMillis = 30000 ms. [org.apache.kafka.clients.producer.KafkaProducer] The reason is that the DropViewParserListener doesn't respect the skipViews flag.

      Description

      If there is a table named "customers", and there is a statement "DROP VIEW IF EXISTS customers", Debezium removes the table from the schema and fails to process any subsequent change in the schema.

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            sergeimorozov Sergei Morozov
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: