airbytehq / airbytehq/airbyte

[source-mongodb-v2] CDC sync force-exits code 2 on idle shutdown: BufferingChangeStreamCursor fetcher blocks in uncancellable stream.cursor() establishment

Abierto
#80,211 4 comentarios 1 reacción 0 asignados Ver en GitHub
autoteam community connectors/source/mongodb-v2 team/use
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

Abrir la guía de contribución

Evaluación

Este issue todavía no se ha evaluado.

Recibe los nuevos issues en tu correo

Un resumen breve de issues de GitHub para principiantes.