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

MySQL connector fails on a DROP TABLE statement if a table needs to be quoted

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Duplicate
    • Icon: Major Major
    • None
    • None
    • mysql-connector
    • None
    • False
    • False
    • Undefined
    • Hide

      Start a connector using the tutorial:

      $ env DEBEZIUM_VERSION=1.5 docker-compose -f docker-compose-mysql.yaml up
Starting tutorial_zookeeper_1 ... done
Starting tutorial_mysql_1     ... done
Starting tutorial_kafka_1     ... done
Starting tutorial_connect_1   ... done
...

$ curl -i -X POST -H "Accept:application/json" -H  "Content-Type:application/json" http://localhost:8083/connectors/ -d @register-mysql.json
HTTP/1.1 201 Created
...

      Execute the following DROP TABLE statement:

      $ docker-compose -f docker-compose-mysql.yaml exec mysql bash -c 'mysql -u $MYSQL_USER -p$MYSQL_PASSWORD inventory'
mysql> DROP TABLE IF EXISTS `foo-bar`;
Query OK, 0 rows affected, 1 warning (0.00 sec)

      Restart the Kafka Connect worker. This will trigger re-reading the database history from the Kafka topic:

      $ docker-compose -f docker-compose-mysql.yaml restart connect

      Observe the messages in the log:

      2021-05-11 21:31:31,147 ERROR  ||  WorkerSourceTask{id=inventory-connector-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]
io.debezium.text.ParsingException: DDL statement couldn't be parsed. Please open a Jira issue with the statement 'DROP TABLE IF EXISTS foo-bar'
mismatched input '-' expecting {<EOF>, '--'}
  at io.debezium.antlr.ParsingErrorListener.syntaxError(ParsingErrorListener.java:43)
  at org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41)
  at org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544)
  at org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327)
  at org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139)
  at io.debezium.ddl.parser.mysql.generated.MySqlParser.root(MySqlParser.java:905)
  at io.debezium.connector.mysql.antlr.MySqlAntlrDdlParser.parseTree(MySqlAntlrDdlParser.java:72)
  at io.debezium.connector.mysql.antlr.MySqlAntlrDdlParser.parseTree(MySqlAntlrDdlParser.java:45)
  at io.debezium.antlr.AntlrDdlParser.parse(AntlrDdlParser.java:80)
  at io.debezium.relational.history.AbstractDatabaseHistory.lambda$recover$1(AbstractDatabaseHistory.java:134)
  at io.debezium.relational.history.KafkaDatabaseHistory.recoverRecords(KafkaDatabaseHistory.java:307)
  at io.debezium.relational.history.AbstractDatabaseHistory.recover(AbstractDatabaseHistory.java:101)
  at io.debezium.relational.HistorizedRelationalDatabaseSchema.recover(HistorizedRelationalDatabaseSchema.java:49)
  at io.debezium.connector.mysql.MySqlConnectorTask.validateAndLoadDatabaseHistory(MySqlConnectorTask.java:311)
  at io.debezium.connector.mysql.MySqlConnectorTask.start(MySqlConnectorTask.java:96)
  at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:130)
  at org.apache.kafka.connect.runtime.WorkerSourceTask.execute(WorkerSourceTask.java:232)
  at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:185)
  at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:234)
  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: org.antlr.v4.runtime.InputMismatchException
  at org.antlr.v4.runtime.DefaultErrorStrategy.sync(DefaultErrorStrategy.java:270)
  at io.debezium.ddl.parser.mysql.generated.MySqlParser.root(MySqlParser.java:890)
  ... 18 more

      Notice that the DDL in the topic appears as DROP TABLE IF EXISTS foo-bar which is indeed invalid from the SQL parser standpoint. At this point, it seems like it's a MySQL bug since it logs an invalid DDL.

      Log in as the root user to MySQL and observe the binlog:

      $ docker-compose -f docker-compose-mysql.yaml exec mysql bash -c 'mysql -u debezium -pdbz'

mysql> SHOW BINARY LOGS;
+------------------+-----------+
| Log_name         | File_size |
+------------------+-----------+
| mysql-bin.000001 |       177 |
| mysql-bin.000002 |   3094876 |
| mysql-bin.000003 |       382 |
| mysql-bin.000004 |       154 |
+------------------+-----------+
4 rows in set (0.00 sec)

mysql> SHOW BINLOG EVENTS IN 'mysql-bin.000003';
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                                                      |
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+
| mysql-bin.000003 |   4 | Format_desc    |    223344 |         123 | Server ver: 5.7.34-log, Binlog ver: 4                                     |
| mysql-bin.000003 | 123 | Previous_gtids |    223344 |         154 |                                                                           |
| mysql-bin.000003 | 154 | Anonymous_Gtid |    223344 |         219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                      |
| mysql-bin.000003 | 219 | Query          |    223344 |         359 | use `inventory`; DROP TABLE IF EXISTS `foo-bar` /* generated by server */ |
| mysql-bin.000003 | 359 | Stop           |    223344 |         382 |                                                                           |
+------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+
5 rows in set (0.00 sec)

      Observe the binlog file contents:

      xxd ~/mysql-bin.000003 | tail -7
00000110: 0008 0008 000c 0169 6e76 656e 746f 7279  .......inventory
00000120: 0069 6e76 656e 746f 7279 0044 524f 5020  .inventory.DROP
00000130: 5441 424c 4520 4946 2045 5849 5354 5320  TABLE IF EXISTS
00000140: 6066 6f6f 2d62 6172 6020 2f2a 2067 656e  `foo-bar` /* gen
00000150: 6572 6174 6564 2062 7920 7365 7276 6572  erated by server
00000160: 202a 2f19 b58d e2ec f79a 6003 7068 0300   */.......`.ph..
00000170: 1700 0000 7e01 0000 0000 ed3e 87fa       ....~......>..

      From the above, it appears that the DDL is logged correctly, so the problem is somewhere between the binlog and the parser (e.g. the binlog sender on the server side or the reader used by the connector).

      Show
      Start a connector using the tutorial : $ env DEBEZIUM_VERSION=1.5 docker-compose -f docker-compose-mysql.yaml up Starting tutorial_zookeeper_1 ... done Starting tutorial_mysql_1 ... done Starting tutorial_kafka_1 ... done Starting tutorial_connect_1 ... done ... $ curl -i -X POST -H "Accept:application/json" -H "Content-Type:application/json" http://localhost:8083/connectors/ -d @register-mysql.json HTTP/1.1 201 Created ... Execute the following DROP TABLE statement: $ docker-compose -f docker-compose-mysql.yaml exec mysql bash -c 'mysql -u $MYSQL_USER -p$MYSQL_PASSWORD inventory' mysql> DROP TABLE IF EXISTS `foo-bar`; Query OK, 0 rows affected, 1 warning (0.00 sec) Restart the Kafka Connect worker. This will trigger re-reading the database history from the Kafka topic: $ docker-compose -f docker-compose-mysql.yaml restart connect Observe the messages in the log: 2021-05-11 21:31:31,147 ERROR || WorkerSourceTask{id=inventory-connector-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] io.debezium.text.ParsingException: DDL statement couldn't be parsed. Please open a Jira issue with the statement 'DROP TABLE IF EXISTS foo-bar' mismatched input '-' expecting {<EOF>, '--'} at io.debezium.antlr.ParsingErrorListener.syntaxError(ParsingErrorListener.java:43) at org.antlr.v4.runtime.ProxyErrorListener.syntaxError(ProxyErrorListener.java:41) at org.antlr.v4.runtime.Parser.notifyErrorListeners(Parser.java:544) at org.antlr.v4.runtime.DefaultErrorStrategy.reportInputMismatch(DefaultErrorStrategy.java:327) at org.antlr.v4.runtime.DefaultErrorStrategy.reportError(DefaultErrorStrategy.java:139) at io.debezium.ddl.parser.mysql.generated.MySqlParser.root(MySqlParser.java:905) at io.debezium.connector.mysql.antlr.MySqlAntlrDdlParser.parseTree(MySqlAntlrDdlParser.java:72) at io.debezium.connector.mysql.antlr.MySqlAntlrDdlParser.parseTree(MySqlAntlrDdlParser.java:45) at io.debezium.antlr.AntlrDdlParser.parse(AntlrDdlParser.java:80) at io.debezium.relational.history.AbstractDatabaseHistory.lambda$recover$1(AbstractDatabaseHistory.java:134) at io.debezium.relational.history.KafkaDatabaseHistory.recoverRecords(KafkaDatabaseHistory.java:307) at io.debezium.relational.history.AbstractDatabaseHistory.recover(AbstractDatabaseHistory.java:101) at io.debezium.relational.HistorizedRelationalDatabaseSchema.recover(HistorizedRelationalDatabaseSchema.java:49) at io.debezium.connector.mysql.MySqlConnectorTask.validateAndLoadDatabaseHistory(MySqlConnectorTask.java:311) at io.debezium.connector.mysql.MySqlConnectorTask.start(MySqlConnectorTask.java:96) at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:130) at org.apache.kafka.connect.runtime.WorkerSourceTask.execute(WorkerSourceTask.java:232) at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:185) at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:234) 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: org.antlr.v4.runtime.InputMismatchException at org.antlr.v4.runtime.DefaultErrorStrategy.sync(DefaultErrorStrategy.java:270) at io.debezium.ddl.parser.mysql.generated.MySqlParser.root(MySqlParser.java:890) ... 18 more Notice that the DDL in the topic appears as DROP TABLE IF EXISTS foo-bar which is indeed invalid from the SQL parser standpoint. At this point, it seems like it's a MySQL bug since it logs an invalid DDL. Log in as the root user to MySQL and observe the binlog: $ docker-compose -f docker-compose-mysql.yaml exec mysql bash -c 'mysql -u debezium -pdbz' mysql> SHOW BINARY LOGS; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 177 | | mysql-bin.000002 | 3094876 | | mysql-bin.000003 | 382 | | mysql-bin.000004 | 154 | +------------------+-----------+ 4 rows in set (0.00 sec) mysql> SHOW BINLOG EVENTS IN 'mysql-bin.000003'; +------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+ | mysql-bin.000003 | 4 | Format_desc | 223344 | 123 | Server ver: 5.7.34-log, Binlog ver: 4 | | mysql-bin.000003 | 123 | Previous_gtids | 223344 | 154 | | | mysql-bin.000003 | 154 | Anonymous_Gtid | 223344 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' | | mysql-bin.000003 | 219 | Query | 223344 | 359 | use `inventory`; DROP TABLE IF EXISTS `foo-bar` /* generated by server */ | | mysql-bin.000003 | 359 | Stop | 223344 | 382 | | +------------------+-----+----------------+-----------+-------------+---------------------------------------------------------------------------+ 5 rows in set (0.00 sec) Observe the binlog file contents: xxd ~/mysql-bin.000003 | tail -7 00000110: 0008 0008 000c 0169 6e76 656e 746f 7279 .......inventory 00000120: 0069 6e76 656e 746f 7279 0044 524f 5020 .inventory.DROP 00000130: 5441 424c 4520 4946 2045 5849 5354 5320 TABLE IF EXISTS 00000140: 6066 6f6f 2d62 6172 6020 2f2a 2067 656e `foo-bar` /* gen 00000150: 6572 6174 6564 2062 7920 7365 7276 6572 erated by server 00000160: 202a 2f19 b58d e2ec f79a 6003 7068 0300 */.......`.ph.. 00000170: 1700 0000 7e01 0000 0000 ed3e 87fa ....~......>.. From the above, it appears that the DDL is logged correctly, so the problem is somewhere between the binlog and the parser (e.g. the binlog sender on the server side or the reader used by the connector).

      If a table name being dropped contains special characters and needs to be quoted, Debezium will fail when parsing the DROP TABLE statement from the binlog.

      The issue is not reproducible with Debezium 1.4 or with 1.5 and with the connector configured with internal.implementation=legacy. Could be related to DBZ-3399.

              Unassigned Unassigned
              sergeimorozov Sergei Morozov (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: