Duplicate Snapshot On Connect Worker Restart - Version 1.5.2.Final

[linga...@gmail.com]

Hello Team,

I noticed that tables were getting snapshotted every time the connect worker was restarted when using version 1.5.2.Final, that is with every restart the topic log-end-offset doubled, tripled and so on. I upgraded to 1.6.0.Final and I did not see this issue. 

Just FYI if anybody is using 1.5.2.Final.

Regards,

Shiva

[Chris Cranford]

Hi Shiva -

So if I understand, the snapshot concludes successfully, but despite that if the connector is restarted after-the-fact, the snapshot is re-executed?

Have you tried 1.5.4.Final to see whether the problem is there too? 
Could you share the connector configuration?

CC

--
You received this message because you are subscribed to the Google Groups "debezium" group.
To unsubscribe from this group and stop receiving emails from it, send an email to debezium+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/debezium/62325558-6a0a-4786-b9af-de77c0410333n%40googlegroups.com.

[Shiva]

Hi Chris,

This issue occurred in our production environment. We had a bunch of connectors running but the snapshot was re-executed only for tables in a single connector when the connect worker was restarted. What was different about this particular connector was that I had deleted and re-created this connector due to a misconfiguration in exclude.columns.

Steps taken to delete the connector:

-Delete connector

-Delete topics associated with each of the tables configured in the connector

-Delete schema history topic(we maintain a separate schema history topic for each connector)

-Send tombstone to Connect Offsets topic with connector name as the key

DBZ version: 1.6.0.final

Please let me know if you need any additional information.

Regards,

Shiva Lingala

On Fri, Jul 9, 2021 at 1:35 AM Shiva <linga...@gmail.com> wrote:

Hi Chris,

Yes, that is correct. After the snapshot concluded successfully and "snapshot_completed" was marked true in connect-offsets topic I still saw the snapshot getting re-executed. I verified this by checking the connect-worker logs and topic message count with each restart.

That said...I am not able to reproduce this issue with my setup using either 1.5.2 or 1.5.4 :|

Thanks for your time.

Regards,
Shiva

[linga...@gmail.com]

Hi Chris,

I can confirm that this behavior is reproducible. I have seen the same thing happen with another connector that was also deleted and re-created due to DDL changes in one of the tables. I tried to get as much as possible from the logs, I hope the snippet below helps. As you can see I had deleted and re-created these two connectors several times.

[2021-09-07 18:44:19,526] INFO Kafka version: 6.2.0-ccs (org.apache.kafka.common.utils.AppInfoParser)
[2021-09-07 18:44:19,526] INFO Kafka commitId: 1a5755cf9401c84f (org.apache.kafka.common.utils.AppInfoParser)
[2021-09-07 18:44:19,526] INFO Kafka startTimeMs: 1631040259526 (org.apache.kafka.common.utils.AppInfoParser)
[2021-09-07 18:44:19,529] INFO [Consumer clientId=consumer-1-3, groupId=1] Cluster ID: oC72WAXWRW6J445vrkPT_w (org.apache.kafka.clients.Metadata)
[2021-09-07 18:44:19,529] INFO [Consumer clientId=consumer-1-3, groupId=1] Subscribed to partition(s): ConnectConfigs-0 (org.apache.kafka.clients.consumer.KafkaConsumer)
[2021-09-07 18:44:19,529] INFO [Consumer clientId=consumer-1-3, groupId=1] Seeking to EARLIEST offset of partition ConnectConfigs-0 (org.apache.kafka.clients.consumer.internals.SubscriptionState)
[2021-09-07 18:44:19,535] INFO [Consumer clientId=consumer-1-3, groupId=1] Resetting offset for partition ConnectConfigs-0 to position FetchPosition{offset=0, offsetEpoch=Optional.empty, currentLeader=LeaderAndEpoch{leader=Optional[kafka:9092 (id: 1 rack: null)], epoch=0}}. (org.apache.kafka.clients.consumer.internals.SubscriptionState)
[2021-09-07 18:44:19,547] INFO Successfully processed removal of connector 'Sink_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,548] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,548] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,549] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,549] INFO Successfully processed removal of connector 'Sink_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,549] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,553] INFO Successfully processed removal of connector 'Sink_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Sink_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Sink_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,554] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,555] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,555] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_18' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,555] INFO Successfully processed removal of connector 'Source_PRDB02_fiNext_PG_7' (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,560] INFO Finished reading KafkaBasedLog for topic ConnectConfigs (org.apache.kafka.connect.util.KafkaBasedLog)
[2021-09-07 18:44:19,560] INFO Started KafkaBasedLog for topic ConnectConfigs (org.apache.kafka.connect.util.KafkaBasedLog)
[2021-09-07 18:44:19,560] INFO Started KafkaConfigBackingStore (org.apache.kafka.connect.storage.KafkaConfigBackingStore)
[2021-09-07 18:44:19,560] INFO [Worker clientId=connect-1, groupId=1] Herder started (org.apache.kafka.connect.runtime.distributed.DistributedHerder)
[2021-09-07 18:44:19,581] INFO [Worker clientId=connect-1, groupId=1] Cluster ID: oC72WAXWRW6J445vrkPT_w (org.apache.kafka.clients.Metadata)
[2021-09-07 18:44:19,582] INFO [Worker clientId=connect-1, groupId=1] Discovered group coordinator kafka:9092 (id: 2147483646 rack: null) (org.apache.kafka.clients.consumer.internals.AbstractCoordinator)
[2021-09-07 18:44:19,584] INFO [Worker clientId=connect-1, groupId=1] Rebalance started (org.apache.kafka.connect.runtime.distributed.WorkerCoordinator)
[2021-09-07 18:44:19,584] INFO [Worker clientId=connect-1, groupId=1] (Re-)joining group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator)
[2021-09-07 18:44:19,591] INFO [Worker clientId=connect-1, groupId=1] (Re-)joining group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator)

Could we force compaction on the connect worker offsets/config topic and may be that can help? I am not sure if this is even possible. A quick workaround would be to rename connectors every time I have to delete them. Unfortunately since automatic DDL change propagation is not easy to implement for SQL servers without downtime/data loss we are going with the simple approach of just reloading tables. We expect DDL changes on at least one table in a week. 

Please let me know if you need any further information and thanks for your time.

Regards,
Shiva