[source-mongodb-v2] CDC sync force-exits code 2 on idle shutdown: BufferingChangeStreamCursor fetcher blocks in uncancellable stream.cursor() establishment
- Lenguaje dominante
- Python
- Estrellas
- 22.1k
- Forks
- 5.3k
- Métricas de merge de PR
- Métricas de PR pendientes
Descripción
### Connector Name
source-mongodb-v2
### Connector Version
2.0.7
### What step the error happened?
During the sync
### Relevant information
**Summary:** A successful, fully state-committed CDC sync force-exits with **code 2** because the Debezium MongoDB change-stream fetcher thread blocks in an **uncancellable cursor-establishment** call during shutdown. This is a `BufferingChangeStreamCursor` defect, reproducible independent of connection-string options, and present in every Debezium version from the currently-pinned 2.6.2 through the latest 3.5.x.
**Confirmed root cause** (`io.debezium.connector.mongodb.events.BufferingChangeStreamCursor$EventFetcher.run`):
```java
try (MongoChangeStreamCursor<...> cursor = stream.cursor()) { // line ~221: BLOCKS here establishing the change stream
cursorRef.compareAndSet(null, cursor); // cursorRef is assigned only AFTER establishment returns
running.set(true);
...
fetchEvents(cursor); // while(isRunning()) loop — never reached
}
```
`EventFetcher.close()` only sets `running=false` and can at most close a **non-null** `cursorRef`. While `stream.cursor()` is still blocking on the initial `$changeStream` aggregate read, `cursorRef` is `null`, so the in-flight establishment cannot be cancelled. Blocking MongoDB driver socket reads do not respond to `Thread.interrupt()`, so:
1. After the idle window (`No records were returned by Debezium in the timeout seconds 1200`), the engine is asked to stop.
2. `BufferingChangeStreamCursor.close()` logs `Awaiting fetcher thread termination` but cannot unblock the fetcher.
3. The engine reports `Connector ... completed normally` / `Engine terminated successfully : true`, and the connector commits the resume token + emits the final state message.
4. The non-daemon `replicator-fetcher-0` thread is still blocked, so `IntegrationRunner.stopOrphanedThreads` force-exits with `System.exit(2)` ~2 min later — failing an attempt that actually succeeded.
This is most likely on **low-traffic collections**, where a resumed change stream has no event to return during establishment.
**Unchanged across Debezium releases.** `BufferingChangeStreamCursor.run()`/`close()` are identical at `v2.6.2.Final` (current pin), `v2.7.0.Final`, and the latest `v3.5.2.Final` (`cursorRef` assigned only after `stream.cursor()` returns; `close()` just flips the running flag). A connector Debezium-version bump will **not** fix this.
**Reproduces independent of connection-string config.** Observed on two unrelated connections:
- One source with `readPreference=secondary&readPreferenceTags=nodeType:ANALYTICS&socketTimeoutMS=...`.
- One source with a **bare** connection string (no `socketTimeoutMS`, no `readPreference`).
Both force-exit code 2 identically. Tuning or removing `socketTimeoutMS`, and changing the read-preference/target node, make no difference — confirming the failure is in cursor establishment, not socket timeout or node selection.
**Environment:** Debezium `2.6.2.Final`, mongo-java-driver `4.11.0`, Java `21.0.6`; workload/orchestrator `2.0.1`; self-hosted via `abctl v0.30.4`; source MongoDB Atlas `8.0` replica set; `mongodb.connection.mode=sharded`, `snapshot.mode=never` (CDC/oplog only).
**Expected:** an idle CDC sync that commits its resume token and logs `completed normally` exits `0`.
**Actual:** force-exits `2`; the attempt is marked failed despite committed state.
**Fix direction.** Primary fix is in the Debezium MongoDB connector: make cursor establishment cancellable so `close()` can close the underlying `MongoChangeStreamCursor`/client even while `cursorRef` is still `null`, unblocking the socket read on shutdown. (Secondary stopgap, Airbyte CDK side: when the engine reported `completed normally` and the final state was emitted, do not `System.exit(FORCED_EXIT_CODE)` solely because of a leftover known MongoDB Debezium fetcher thread.)
### Relevant log output
```text
INFO i.a.c.i.d.i.DebeziumRecordIterator(requestClose):275 No records were returned by Debezium in the timeout seconds 1200, closing the engine and iterator
INFO i.d.e.EmbeddedEngine(stop):964 Waiting for PT5M for connector to stop
INFO i.d.c.m.e.BufferingChangeStreamCursor(close):403 Awaiting fetcher thread termination
INFO i.a.i.s.m.c.MongoDbCdcStateHandler(saveState):36 Saving Debezium state ... resume_token=826A32D408000003C4...
INFO i.a.c.i.s.r.s.SourceStateIterator(computeNext):84 sending final state message, with count per stream: {}
INFO i.a.c.i.d.i.DebeziumRecordPublisher(start$lambda$1):63 Connector 'io.debezium.connector.mongodb.MongoDbConnector' completed normally.
WARN i.a.c.i.b.IntegrationRunner$Companion(stopOrphanedThreads):489 Active non-daemon thread info: debezium-mongodbconnector-...-replicator-fetcher-0 (RUNNABLE)
Thread stacktrace: java.base/sun.nio.ch.Net.poll(Native Method)
at com.mongodb.internal.connection.SocketStream.read(SocketStream.java:175)
at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:372)
at com.mongodb.internal.operation.AggregateOperationImpl.execute(AggregateOperationImpl.java:193)
at com.mongodb.internal.operation.ChangeStreamOperation.execute(ChangeStreamOperation.java:185)
at com.mongodb.client.internal.ChangeStreamIterableImpl.execute(ChangeStreamIterableImpl.java:212)
at com.mongodb.client.internal.ChangeStreamIterableImpl.cursor(ChangeStreamIterableImpl.java:187)
at io.debezium.connector.mongodb.events.BufferingChangeStreamCursor$EventFetcher.run(BufferingChangeStreamCursor.java:221)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at java.base/java.lang.Thread.run(Thread.java:1583)
ERROR i.a.c.i.b.IntegrationRunner$Companion(stopOrphanedThreads$lambda$5):507 Failed to interrupt children non-daemon threads, forcefully exiting NOW...
ERROR Source process exited with non-zero exit code 2
```
### Contribute
- [x] Yes, I want to contribute
---
**Internal Tracking:** https://github.com/airbytehq/oncall/issues/12911
Guía de contribución
Evaluación
Este issue todavía no se ha evaluado.