Azure / Azure/azure-functions-host
Worker-channel ShutdownAndDispose can hang on timeout-recovery path, leaving host at 0 workers
- Dominant language
- C#
- Stars
- 2k
- Forks
- 482
- Avg merge
- 2d 10h
- Merged PRs (30d)
- 36
Description
# Worker-channel ShutdownAndDispose can hang on timeout-recovery path, leaving host at 0 workers
## Summary
On the worker **timeout-recovery** path, `RpcWorkerChannelExtensions.ShutdownAndDispose` can **hang and never return**. Because `RpcFunctionInvocationDispatcher.DisposeAndRestartWorkerChannel` `await`s the shutdown *before* calling `StartWorkerChannel`, the worker is **never restarted** and the host is left with **0 workers**, failing every invocation with `Did not find any initialized language workers` until the app is manually restarted. The host stays HTTP-healthy throughout, so nothing auto-heals.
## Environment
- dotnet-isolated, **host 4.1053** (incident build `4.1053.200`; code below verified against tag `v4.1053.100`), Windows, App Service (Dedicated/Elastic Premium)
- On App Service the process registry is `EmptyProcessRegistry`, not `JobObjectRegistry` (see `RpcServiceCollectionExtensions.AddProcessRegistry` — `JobObjectRegistry` is only wired on Windows **non**-App-Service). So this is **distinct** from the `JobObjectRegistry` shutdown deadlock addressed in #11851 / investigated in #11807.
## Trigger vs. root cause
A function **timeout is the trigger** — it raises the worker error that puts the host on the `DisposeAndRestartWorkerChannel` recovery path. It is **not** the hang mechanism itself: the hang is in the channel `Dispose()` step, which runs on any worker teardown.
The likely **precondition** for the hang is the *state* the timeout creates: at teardown the channel had **concurrent in-flight invocations being aborted**, a `WorkerTerminate` handshake in flight, and the worker process exiting (cleanly, `code 0`) ~1s later. This also explains why it is **intermittent** — it needs concurrent in-flight traffic at the instant of the timeout-triggered dispose; an idle dispose does not hit it. (Precondition is a hypothesis, not yet proven.)
## Observed production log order (single instance, sanitized)
```
Timeout value of 00:30:00 exceeded by function ''. Initiating cancellation.
Executed '' (Failed, Duration=1800050ms)
A function timeout has occurred. Restarting worker process …
Restarting channel with workerId '' that is executing invocation '' and timed out.
Attempting to dispose webhost or jobhost channel …, runtime: 'dotnet-isolated'
Disposing language worker channel with id: ← LAST recovery log
Worker '' encountered a fatal error. Failing invocation: '' (x2, one per in-flight invocation)
Sending WorkerTerminate message with grace period of 5 seconds.
[channel] received : None
Process has exited with code 0. ← worker exits cleanly
— then nothing for ~2h until manual restart —
```
Key signals:
- **`Disposed language worker channel with id:…` is never logged**, although it normally follows every `Disposing …` (the two lines bracket the `ShutdownAndDispose` call in `JobHostRpcWorkerChannelManager.ShutdownChannelIfExistsAsync`). On the same instance across the surrounding days, `Disposing`/`Disposed` counts were 7/6 and 5/4 — i.e. exactly one dispose never completed. → the thread is **stuck inside `ShutdownAndDispose`**.
- No `Restarting worker channel for runtime …`, no `Initiating Worker Process start up`, no `Error while shutting down channel`, no `Exceeded language worker restart retry count` → `StartWorkerChannel` was **never reached**; this is **not** the restart-*decision* path in #10683.
- `Sending WorkerTerminate` / `Process exited code 0` are logged, and the aborted invocations complete — so `Shutdown()` itself **returned**; the hang is in the subsequent channel **`Dispose()`** step, *after* the worker process already exited. Note there were **two concurrent in-flight invocations** on the worker at teardown.
## App health during the ~2h window (host process)
| Phase | avg CPU% | avg mem (MB) |
|---|---|---|
| pre-incident | ~148 | ~2,460 |
| **stuck (~2h)** | **~1** | **~340** |
| post manual restart | ~11 | ~870 |
CPU **collapsed ~190% → ~1%** and memory dropped as the worker process exited and was never replaced. This is **not** resource exhaustion (no OOM, no CPU spin) — the instance went **alive-but-idle**. The near-zero CPU also argues *against* a thread-pool-starvation style deadlock and *for* a genuine wait that never completes.
## Where it hangs (host 4.1053)
`JobHostRpcWorkerChannelManager.ShutdownChannelIfExistsAsync`:
```csharp
_logger.LogDebug("Disposing language worker channel with id:{id}", id); // logged
rpcChannel.ShutdownAndDispose(workerException, _logger); // never returns
_logger.LogDebug("Disposed language worker channel with id:{id}", id); // NEVER logged
```
`ShutdownAndDispose` (`RpcWorkerChannelExtensions`):
```csharp
channel.Shutdown(exception); // returns — WorkerTerminate + process-exit are logged afterwards
(channel as IDisposable)?.Dispose(); // WorkerChannel.Dispose() — fully SYNCHRONOUS on 4.1053
```
On 4.1053 `WorkerChannel.Dispose()` → `Dispose(true)` runs synchronously:
- `GrpcWorkerChannel`: `StopWorkerProcess()` (send `WorkerTerminate`, bounded 5s `WaitForProcessExit` — worker exited `code 0`), then `base.Dispose(true)`
- `WorkerChannel.Dispose(true)`: remove in-flight invocations (message-dispatcher dispose = `Writer.TryComplete()`), dispose metric/init/reload tasks + timer, unlink inputs, `DisposeWorkerResources()` (dispose the already-exited worker process), dispose event subscriptions, `_eventManager.RemoveGrpcChannels()` (`Writer.TryComplete()`)
Because `Shutdown()` returned and the worker exited cleanly, the hang is **inside `channel.Dispose()`, after process exit**. **The exact blocking sub-step is not yet identified** — none of the synchronous steps above has an obvious unbounded wait, so pinning it likely needs a memory/thread dump from the next occurrence (e.g. a lock or a wait not visible from static analysis).
> Note: the `dev` branch has since refactored this area into a separate `Functions.Rpc.Server` assembly, where `WorkerChannel` is `IAsyncDisposable` and `Dispose()` is sync-over-async (`DisposeAsync().AsTask().GetAwaiter().GetResult()` → `_ownedChannel.DisposeAsync()`). That is **not** the code 4.1053 runs; any tracing/repro for this incident must target the 4.1053 line.
## Repro hint
Drive **≥2 concurrent long-running invocations** on a single worker and force a **timeout-triggered** teardown (so the channel is disposed while invocations are in-flight and the worker is terminating) — not an idle dispose. The idle path completes normally.
## Impact
Single function timeout can strand an instance at 0 workers for hours; only manual restart / scale recovers it. Host reports healthy, so no auto-heal.
## Related
#10683 (same end state, different mechanism), #11807 / #11851 (JobObjectRegistry dispose deadlock — different registry path), #9443, #5651.
Contributor guide
Assessment
This issue has not been assessed yet.