ERROR Producer failure when taking an adhoc snapshot using Debezium MongoDB Connector
235 views
Skip to first unread message
Kay Khan
Jul 29, 2023, 9:25:09 AM7/29/23
to debezium
We have Kafka and Kafka Connect deployed via AWS MSK (3.4.0) and AWS MSK Connect (2.7.1)
We are attempting to take an adhoc source snapshot via the debezium mongodb connector (https://debezium.io/documentation/reference/2.3/connectors/mongodb.html#mongodb-performing-a-snapshot).
But, after it is initiated it collects a batch of data (see a spike in number of messages for the topic and then it stops). We receive the following errors
**Error**
> 2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28
> 21:43:41,205] ERROR [mongodb-default|task-0] Producer
> failure (io.debezium.pipeline.ErrorHandler:57)
> msk-mongodb-default Link
**MSK Connect Debezium Configuration**
```
connector_configuration = {
"tasks.max" : 5
"connector.class" : "io.debezium.connector.mongodb.MongoDbConnector",
"mongodb.connection.string" : "${local.mongodb_secrets.CONNECTION}/?replicaSet=rs0&authSource=admin&directConnection=true",
"topic.prefix" : "mongodb.default",
"snapshot.max.threads" : 4
"capture.mode" : "change_streams_update_full_with_pre_image"
//"database.include.list" : "test-kafka"
"collection.include.list" : "steamspy.allgamesbyowners,steam.ccu"
"signal.enabled.channels" : "source,kafka"
"signal.data.collection" : "debezium.signals"
"signal.kafka.topic" : "debezium.signals.channel"
"signal.kafka.bootstrap.servers" : module.prod_msk_default.bootstrap_brokers_sasl_iam
"signal.consumer.security.protocol" : "SASL_SSL"
"signal.consumer.sasl.mechanism" : "AWS_MSK_IAM"
"signal.consumer.sasl.jaas.config" : "software.amazon.msk.auth.iam.IAMLoginModule required;"
"signal.consumer.sasl.client.callback.handler.class" : "software.amazon.msk.auth.iam.IAMClientCallbackHandler"
}
```
**Source Signal Sent**
```
db.getCollection("signals").insertOne({"type":"execute-snapshot","data": {"data-collections": ["steam.ccu"], "type": "INCREMENTAL"}})
```
**Full Stack Trace**
```
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] Opened connection [connectionId{localValue:11, serverValue:25819743}] to mongo.acme.com:27017 (org.mongodb.driver.connection:71) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:41mongodb-default|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:57) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] java.lang.NullPointerException mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.CommonOffsetContext.getSourceInfo(CommonOffsetContext.java:24) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.buildNotificationWith(IncrementalSnapshotNotificationService.java:154) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.notifyInProgress(IncrementalSnapshotNotificationService.java:130) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.lambda$readChunk$8(MongoDbIncrementalSnapshotChangeEventSource.java:344) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.notifyReplicaSets(MongoDbIncrementalSnapshotChangeEventSource.java:439) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:263) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:57) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$initStreamEvents$3(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Optional.ifPresent(Optional.java:183) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.initStreamEvents(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:203) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:172) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:118) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] Connected metrics set to 'false' (io.debezium.pipeline.ChangeEventSourceCoordinator:282) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] WorkerSmongodb-default-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask:485) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] WorkerSmongodb-default-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask:502) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:41mongodb-default|task-0] WorkerSmongodb-default-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:191) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped. mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:72) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:125) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] Caused by: java.lang.NullPointerException mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
```
Kafka Connect then attempts to restart and throws the error
```
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:47:42mongodb-default|task-0] WorkerSmongodb-default-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:191) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped. mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:72) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:125) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] Caused by: java.lang.NullPointerException mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.CommonOffsetContext.getSourceInfo(CommonOffsetContext.java:24) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.buildNotificationWith(IncrementalSnapshotNotificationService.java:154) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.notifyInProgress(IncrementalSnapshotNotificationService.java:130) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.lambda$readChunk$8(MongoDbIncrementalSnapshotChangeEventSource.java:344) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.notifyReplicaSets(MongoDbIncrementalSnapshotChangeEventSource.java:439) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.readChunk(MongoDbIncrementalSnapshotChangeEventSource.java:342) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:263) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:57) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$initStreamEvents$3(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Optional.ifPresent(Optional.java:183) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.initStreamEvents(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:203) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:172) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:118) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] ... 5 more
```
We are attempting to take an adhoc source snapshot via the debezium mongodb connector (https://debezium.io/documentation/reference/2.3/connectors/mongodb.html#mongodb-performing-a-snapshot).
But, after it is initiated it collects a batch of data (see a spike in number of messages for the topic and then it stops). We receive the following errors
**Error**
> 2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28
> 21:43:41,205] ERROR [mongodb-default|task-0] Producer
> failure (io.debezium.pipeline.ErrorHandler:57)
> msk-mongodb-default Link
**MSK Connect Debezium Configuration**
```
connector_configuration = {
"tasks.max" : 5
"connector.class" : "io.debezium.connector.mongodb.MongoDbConnector",
"mongodb.connection.string" : "${local.mongodb_secrets.CONNECTION}/?replicaSet=rs0&authSource=admin&directConnection=true",
"topic.prefix" : "mongodb.default",
"snapshot.max.threads" : 4
"capture.mode" : "change_streams_update_full_with_pre_image"
//"database.include.list" : "test-kafka"
"collection.include.list" : "steamspy.allgamesbyowners,steam.ccu"
"signal.enabled.channels" : "source,kafka"
"signal.data.collection" : "debezium.signals"
"signal.kafka.topic" : "debezium.signals.channel"
"signal.kafka.bootstrap.servers" : module.prod_msk_default.bootstrap_brokers_sasl_iam
"signal.consumer.security.protocol" : "SASL_SSL"
"signal.consumer.sasl.mechanism" : "AWS_MSK_IAM"
"signal.consumer.sasl.jaas.config" : "software.amazon.msk.auth.iam.IAMLoginModule required;"
"signal.consumer.sasl.client.callback.handler.class" : "software.amazon.msk.auth.iam.IAMClientCallbackHandler"
}
```
**Source Signal Sent**
```
db.getCollection("signals").insertOne({"type":"execute-snapshot","data": {"data-collections": ["steam.ccu"], "type": "INCREMENTAL"}})
```
**Full Stack Trace**
```
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] Opened connection [connectionId{localValue:11, serverValue:25819743}] to mongo.acme.com:27017 (org.mongodb.driver.connection:71) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:41mongodb-default|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:57) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] java.lang.NullPointerException mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.CommonOffsetContext.getSourceInfo(CommonOffsetContext.java:24) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.buildNotificationWith(IncrementalSnapshotNotificationService.java:154) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.notifyInProgress(IncrementalSnapshotNotificationService.java:130) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.lambda$readChunk$8(MongoDbIncrementalSnapshotChangeEventSource.java:344) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.notifyReplicaSets(MongoDbIncrementalSnapshotChangeEventSource.java:439) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:263) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:57) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$initStreamEvents$3(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Optional.ifPresent(Optional.java:183) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.initStreamEvents(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:203) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:172) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:118) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] Connected metrics set to 'false' (io.debezium.pipeline.ChangeEventSourceCoordinator:282) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] WorkerSmongodb-default-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask:485) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:4mongodb-default|task-0] WorkerSmongodb-default-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask:502) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:43:41mongodb-default|task-0] WorkerSmongodb-default-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:191) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped. mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:72) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:125) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] Caused by: java.lang.NullPointerException mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:43:41.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
```
Kafka Connect then attempts to restart and throws the error
```
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] [2023-07-28 21:47:42mongodb-default|task-0] WorkerSmongodb-default-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:191) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped. mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:72) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:125) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.lang.Thread.run(Thread.java:829) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] Caused by: java.lang.NullPointerException mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.concurrent.ConcurrentHashMap.containsKey(ConcurrentHashMap.java:964) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Collections$SetFromMap.contains(Collections.java:5564) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.isInitialSyncOngoing(SourceInfo.java:408) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.SourceInfo.snapshot(SourceInfo.java:473) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfoStructMaker.commonStruct(AbstractSourceInfoStructMaker.java:64) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:39) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbSourceInfoStructMaker.struct(MongoDbSourceInfoStructMaker.java:14) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.AbstractSourceInfo.struct(AbstractSourceInfo.java:77) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.CommonOffsetContext.getSourceInfo(CommonOffsetContext.java:24) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.buildNotificationWith(IncrementalSnapshotNotificationService.java:154) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.notification.IncrementalSnapshotNotificationService.notifyInProgress(IncrementalSnapshotNotificationService.java:130) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.lambda$readChunk$8(MongoDbIncrementalSnapshotChangeEventSource.java:344) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.notifyReplicaSets(MongoDbIncrementalSnapshotChangeEventSource.java:439) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.readChunk(MongoDbIncrementalSnapshotChangeEventSource.java:342) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:263) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource.init(MongoDbIncrementalSnapshotChangeEventSource.java:57) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$initStreamEvents$3(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at java.base/java.util.Optional.ifPresent(Optional.java:183) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.initStreamEvents(ChangeEventSourceCoordinator.java:221) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:203) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:172) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:118) mongodb-default Link
2023-07-28T21:47:42.000Z [Worker-0c6eca6069786095a] ... 5 more
```
Kay Khan
Jul 29, 2023, 11:18:37 AM7/29/23
to debezium
I just wanted to update that directly before receiving the `Producer failure (io.debezium.pipeline.ErrorHandler:57)` i see the following notable logs. This one (No server chosen) particularly stands out as it is repeated multiple times.
```
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:08,071] INFO [mongodb-default|task-0] No server chosen by com.mongodb.client.internal.MongoClientDelegate$1@418160c from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=mongo.acme.com:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out (org.mongodb.driver.cluster:71)
```
```
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:07,728] INFO [mongodb-default|task-0] Requested 'INCREMENTAL' snapshot of data collections '[steam.ccu]' with additional condition 'No condition passed' and surrogate key 'PK of table will be used' (io.debezium.pipeline.signal.actions.snapshotting.ExecuteSnapshot:53)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:08,065] INFO [mongodb-default|task-0] Incremental snapshot for collection 'rs0.steam.ccu' will end at position [64c52aa52eac590008db0105] (io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource:323)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:08,071] INFO [mongodb-default|task-0] No server chosen by com.mongodb.client.internal.MongoClientDelegate$1@418160c from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=mongo.acme.com:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out (org.mongodb.driver.cluster:71)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:08,075] INFO [mongodb-default|task-0] Opened connection [connectionId{localValue:30, serverValue:26102194}] to mongo.acme.com:27017 (org.mongodb.driver.connection:71)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:06:08,078] INFO [mongodb-default|task-0] Monitor thread successfully connected to server with description ServerDescription{address=mongo.acme.com:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=17, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2214925, setName='rs0', canonicalAddress=psmdb-db-rs0-0.psmdb-db-rs0.mongodb.svc.cluster.local:27017, hosts=[psmdb-db-rs0-0.psmdb-db-rs0.mongodb.svc.cluster.local:27017], passives=[], arbiters=[], primary='psmdb-db-rs0-0.psmdb-db-rs0.mongodb.svc.cluster.local:27017', tagSet=TagSet{[Tag{name='podName', value='psmdb-db-rs0-0'}, Tag{name='serviceName', value='psmdb-db'}]}, electionId=7fffffff0000000000000001, setVersion=3, topologyVersion=TopologyVersion{processId=646b5ab9f343d468413a4833, counter=8}, lastWriteDate=Sat Jul 29 15:06:07 UTC 2023, lastUpdateTimeNanos=1796842316361} (org.mongodb.driver.cluster:71)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:07:08,396] INFO [mongodb-default|task-0] WorkerSourceTask{id=mongodb-default-0} Source task finished initialization and start (org.apache.kafka.connect.runtime.WorkerSourceTask:233)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:07:08,645] INFO [mongodb-default|task-0] Incremental snapshot in progress, need to read new chunk on start (io.debezium.connector.mongodb.MongoDbIncrementalSnapshotChangeEventSource:260)
[Worker-0338b124ed44a6e7a] [2023-07-29 15:07:08,674] INFO [mongodb-default|task-0] No server chosen by com.mongodb.client.internal.MongoClientDelegate$1@7c200a56 from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=mongo.acme.com:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out (org.mongodb.driver.cluster:71)
```
Vinh Phạm
Nov 4, 2023, 1:18:57 PM11/4/23
to debezium
Hi Kay,
Have you been able to find a solution for this? I'm currently having the same issue.
When an incremental snapshot is running for mongo and restart happens, we cannot resume the connector. It will throw an NPE just like you have
jiri.p...@gmail.com
Nov 5, 2023, 11:52:12 PM11/5/23
to debezium
Hi,
what version of Debezium do you use? Could you please describe how exactly this happens? Is i excatly the same stacktrace?
It seems the issue was not logged into Jira is it was probably overlooked. Could you please create it there so it is properly handled?
Thanks a lot
J.
Mario Fiore Vitale
Nov 6, 2023, 3:31:02 AM11/6/23
to debezium
Hi,
can you please confirm you are using Debezium 2.3? The NPE issue should have been solved with 2.4 release.
Thanks,
Mario.
Vinh Phạm
Nov 6, 2023, 9:42:41 AM11/6/23
to debezium
Yes, I was using Debezium 2.3, let me test this again with 2.4.
The issue is when I run incremental snapshot on MongoDB connector, it cannot resume when the connector is restarted. The way to reproduce this is very simple, execute the incremental snapshot and restart the connector. When resume, It will throw the exact stacktrace in the post
Kay Khan
Nov 6, 2023, 9:54:01 AM11/6/23
to debezium
Im assuming you are using MSK Connect Serverless ?
If that is the case it will not work and you need to use the provisioned version. The doucmentation does not explicity mention debezium mongodb but i came to find this out https://docs.aws.amazon.com/msk/latest/developerguide/msk-connect-troubleshooting.html,
ref: https://debezium.zulipchat.com/#narrow/stream/302529-community-general/topic/ERROR.20Producer.20failure.20-.20When.20taking.20an.20adhoc.20snapshot
If that is the case it will not work and you need to use the provisioned version. The doucmentation does not explicity mention debezium mongodb but i came to find this out https://docs.aws.amazon.com/msk/latest/developerguide/msk-connect-troubleshooting.html,
ref: https://debezium.zulipchat.com/#narrow/stream/302529-community-general/topic/ERROR.20Producer.20failure.20-.20When.20taking.20an.20adhoc.20snapshot
Reply all
Reply to author
Forward
0 new messages