Details
-
Bug
-
Resolution: Won't Do
-
Major
-
None
-
0.9.5.Final
-
None
-
Incorrectly checking if the `connect-offsets` topic was empty. Most likely, it wasn't, despite the claim it was, invalidating the rest of assumptions.
Description
A bit of a long story here. I'll try to go step-by-step
1. We had a bunch of DBZ connectors deployed using non-GTID configuration (our server didn't have it enabled).
2. We upgraded the RDS MySQL instance to support GTID and enabled it as per debezium instructions.
3. We restarted the connectors and we got errors back. At that point, we assumed that the reason was the connect-offsets topic had "mixed" records: some without GTIDs and some with GTIDs. Tombstoning didn't make much of a difference between the tombstone records were there, but the compaction didn't kick in so the old records still exist.
4. At some point, we decided to change the retention.ms to 1 second to purge the topic and re-deploy the connectors again.
5. This did the trick and the connectors went healthy again. The retention.ms configuration was removed from the topic configuration, failing back to broker defaults (Kafka default of 7 days).
This was all good, then problems arose again.
1. 12 hours later there seems to have been a rebalance and the connectors restarted. When they did, they failed. We saw errors like this in the logs:
msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,811 INFO MySQL current GTID set 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-15192 does contain the GTID set required by the connector 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 (io.debezium.connector.mysql.MySqlConnectorTask) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,814 INFO Requested thread factory for connector MySqlConnector, id = com.nutmeg.customer.cdc-customer-personal-details named = binlog-client (io.debezium.util.Threads) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO GTID set purged on server: 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-12855 (io.debezium.connector.mysql.BinlogReader) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO Attempting to generate a filtered GTID set (io.debezium.connector.mysql.MySqlTaskContext) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO GTID set from previous recorded offset: 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 (io.debezium.connector.mysql.MySqlTaskContext) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO GTID set available on server: 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-15192 (io.debezium.connector.mysql.MySqlTaskContext) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO Final merged GTID set to use when connecting to MySQL: 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 (io.debezium.connector.mysql.MySqlTaskContext) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO Registering binlog reader with GTID set: 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 (io.debezium.connector.mysql.BinlogReader) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,820 INFO Creating thread debezium-mysqlconnector-com.nutmeg.customer.cdc-customer-personal-details-binlog-client (io.debezium.util.Threads) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,822 INFO Creating thread debezium-mysqlconnector-com.nutmeg.customer.cdc-customer-personal-details-binlog-client (io.debezium.util.Threads) [blc-nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306] msk-connect-68f4dbb775-hqt4s msk-connect Jul 08, 2019 11:04:56 AM com.github.shyiko.mysql.binlog.BinaryLogClient connect msk-connect-68f4dbb775-hqt4s msk-connect INFO: Connected to nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306 at 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 (sid:6206, cid:386864) msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,904 INFO Connected to MySQL binlog at nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306, starting at GTIDs 5967fb92-30cd-11e7-bfb0-066b2424aae1:1-4984 and binlog file 'mysql-bin-changelog.378162', pos=337, skipping 0 events plus 0 rows (io.debezium.connector.mysql.BinlogReader) [blc-nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,904 INFO Creating thread debezium-mysqlconnector-com.nutmeg.customer.cdc-customer-personal-details-binlog-client (io.debezium.util.Threads) [blc-nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,904 INFO WorkerSourceTask{id=com.nutmeg.customer.cdc-customer-personal-details-0} Source task finished initialization and start (org.apache.kafka.connect.runtime.WorkerSourceTask) [pool-6-thread-4] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,943 ERROR Error during binlog processing. Last offset stored = null, binlog reader near position = /4 (io.debezium.connector.mysql.BinlogReader) [blc-nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:3306] msk-connect-68f4dbb775-hqt4s msk-connect 2019-07-08 11:04:56,943 INFO Stopped reading binlog after 0 events, no new offset was recorded (io.debezium.connector.mysql.BinlogReader) [blc-nm-sit.cov6qftddrxt.eu-west-1.rds.amazonaws.com:33
2. We tried restarting and it still failed. After a few different attempts, it seems the only thing that brought them back was to remove the `-history` topic. Inside this topic there are entries that contain GTIDs, so my assumption is that might be from where the connector was picking up a GTID value that wasn't available in the server anymore.
