bug(cdc/postgres): zombie walsender process locking postgres replication slot
## Summary
`DbzCdcEngineRunner.stop()` is non-blocking. When the coordinator thread is stuck in
uninterruptible native JDBC I/O, stop signals are ignored, the keep-alive thread
continues sending `StandbyStatusUpdate` to Postgres every 10 s, and the replication slot
stays locked indefinitely — `wal_sender_timeout` cannot fire.
---
## Root cause
### 1. `stop()` does not wait for thread termination
```java
// DbzCdcEngineRunner.java
public void stop() throws Exception {
if (isRunning()) {
engine.stop(); // sets stop flag, returns after internal timeout
cleanUp();
LOG.info("engine#{} terminated", engine.getId()); // premature: threads still running
}
}
private void cleanUp() {
running.set(false);
executor.shutdownNow(); // Thread.interrupt() only — no awaitTermination()
}
```
`executor.shutdownNow()` interrupts the runner thread (`rw-dbz-engine-runner-N`). The
coordinator and keep-alive threads run in their own `ExecutorService` instances created
inside Debezium; they are not owned by this executor and are unaffected.
### 2. The coordinator is blocked in non-interruptible native JDBC I/O
```java
// PostgresStreamingChangeEventSource.java — processMessages(), every loop iteration
connection.commit(); // regular JDBC connection — Thread.interrupt() does not unblock this
```
When `connection.commit()` blocks (e.g. on a transient database-side condition),
`Thread.interrupt()` sets the interrupt flag but does not unblock the native socket call.
`context.isRunning()` is never re-checked. `execute()` never returns.
### 3. The keep-alive thread is never stopped
```java
// PostgresStreamingChangeEventSource.java:221-225
stream.startKeepAlive(
Threads.newSingleThreadExecutor(
PostgresConnector.class, connectorConfig.getLogicalName(), "keep-alive"));
```
`stopKeepAlive()` is called only in `cleanUpStreamingOnStop()` inside the `finally` block
of `execute()`. Because `execute()` never returns, `stopKeepAlive()` is never called.
**Result:** every call to `runner.stop()` (on restarts, rescheduling, or meta recovery)
logs `"engine terminated"` while the coordinator and keep-alive threads remain alive.
The keep-alive thread keeps the walsender alive indefinitely. New engine instances fail
to acquire the slot:
```
PSQLException: ERROR: replication slot "..." is active for PID <zombie>
```
---
## Observed in production
The following was observed on a PostgreSQL 15 Aurora cluster with `wal_sender_timeout = 1min`.
The zombie walsender survived **7 h 46 min** without triggering `wal_sender_timeout`.
`pg_stat_replication` across three measurements taken over ~7 minutes showed:
| Column | Value |
|--------|-------|
| `state` | `streaming` |
| `write_lsn` | non-null (one initial status update was sent at connect time) |
| `flush_lsn` | **NULL throughout** — coordinator never committed a single offset |
| `reply_time` | **advancing** (+20 ms in 21 s wall clock, +430 ms in 438 s) |
| `confirmed_flush_lsn` | **frozen** — identical value across all three measurements |
`reply_time` advancing proves Aurora was actively receiving `StandbyStatusUpdate` messages
from the JVM — a transparent TCP proxy cannot synthesise replication protocol messages, so
the keep-alive thread was demonstrably alive and sending. With `wal_sender_timeout = 1min`,
a connection that receives a keepalive every 10 s will never be timed out regardless of how
long the coordinator has been stuck.
WAL accumulated ~3.2 GB over the zombie's lifetime with no sign of self-healing.
Every new engine startup produced the following in the connector-node logs, then exhausted
its retry budget and cycled:
```
WARN Failed to start replication stream at LSN{...}, attempt number 2 over 6
thread="debezium-postgresconnector-<source-id>-change-event-source-coordinator"
error="PSQLException: ERROR: replication slot \"...\" is active for PID <zombie>"
```
Retries 2–6 were observed within a ~40 s window; the engine then re-initialised and the
cycle repeated. This continued for hours.
---
## Diagnostic signal
A zombie of this type is identifiable in `pg_stat_replication`:
```sql
SELECT pid, slot_name, flush_lsn, now() - backend_start AS age
FROM pg_stat_replication r
JOIN pg_replication_slots s ON r.pid = s.active_pid
WHERE r.flush_lsn IS NULL
AND r.state = 'streaming'
AND now() - r.backend_start > interval '5 minutes';
```
`flush_lsn IS NULL` with `state = streaming` means the coordinator never committed a
single offset — it is stuck before the first successful processing iteration. This query
would have fired within 5 minutes of the zombie being created.
---
## Proposed fix
After `executor.shutdownNow()`, wait for termination with a bounded timeout. If the
coordinator is still stuck in native JDBC I/O after the timeout, force-close the
`PostgresConnection` from outside — this throws a `SocketException` inside
`connection.commit()`, which unwinds through `processMessages()` → `execute()`'s catch
block → `finally` → `cleanUpStreamingOnStop()`, which stops the keep-alive and closes
the replication connection correctly.
```java
public void stop() throws Exception {
if (isRunning()) {
engine.stop();
cleanUp();
if (!executor.awaitTermination(30, TimeUnit.SECONDS)) {
LOG.warn("engine#{} did not stop within 30s, force-closing connections",
engine.getId());
engine.forceClose(); // new: closes PostgresConnection to unblock native I/O
executor.awaitTermination(10, TimeUnit.SECONDS);
}
LOG.info("engine#{} terminated", engine.getId());
}
}
```
`engine.forceClose()` needs to expose a path to close the `PostgresConnection` held by
`PostgresStreamingChangeEventSource`. The exact approach is left to maintainer discretion.
---
## Related
- **#15739** (closed/not-planned): stack trace shows
`ChangeEventSourceCoordinator.stop() → awaitTermination()` interrupted during stop —
confirms this code path was already observed to be fragile.
- **#25200** (open, P-high): same observable symptom ("CDC source silent for hours,
requires manual pod restart") — proposes heartbeat-based stall detection. This issue
proposes fixing the underlying cause.
0 条评论