Fix sequential timeout stacking in shutdown budget

The same shutdown_timeout was used for both uvicorn handler drain AND
queue.stop() consumer drain — sequential phases sharing Docker's
wall-clock budget. With 30s each, worst case was 60s, exceeding
the 35s stop_grace_period and causing SIGKILL.

Fix: uvicorn gets a fixed 3s drain (handlers just re-raise), queue
gets the full shutdown_timeout. Docker grace = 3 + timeout + 5s safety.

Also adds shutdown observability: startup logs the timing chain,
queue.stop() logs remaining audio vs available budget.
This commit is contained in:
Ryan Malloy 2026-03-02 18:28:04 -07:00
parent d10eb9ab57
commit 79bfe2a89b
5 changed files with 36 additions and 8 deletions

View File

@ -122,7 +122,12 @@ When a currently-playing item is explicitly cancelled, pw-play is killed immedia
On `docker compose down` or `make restart`, the server lets the currently-playing speech finish before stopping — no more mid-sentence cutoffs.
**How it works:** `queue.stop()` sets a flag and waits up to `shutdown_timeout` seconds for the consumer to finish the current item. If the timeout expires, it falls back to hard cancel. Docker's `stop_grace_period: 35s` gives the 30s shutdown timeout room to complete before SIGKILL.
**How it works:** SIGTERM triggers a two-phase shutdown that shares Docker's wall-clock budget:
1. **Phase 1 — Handler drain (3s fixed):** Uvicorn cancels in-flight `speak()` handlers. The handlers re-raise `CancelledError` without touching the consumer — audio keeps playing.
2. **Phase 2 — Queue drain (`shutdown_timeout`, default 30s):** Lifespan finalizer calls `queue.stop()`, which waits for the consumer to finish the current audio. If the timeout expires, it force-cancels.
Docker's `stop_grace_period` must exceed the total: `3s + shutdown_timeout + 5s safety margin` (default 38s). If the max expected audio length exceeds `shutdown_timeout`, increase both `TTS_SHUTDOWN_TIMEOUT` and `stop_grace_period`.
**Entry tone timing:** The Nextel chirp fires immediately when `speak()` is called (before synthesis), acting as an audible "I heard you" that covers the 1-3s synthesis latency. Exit/standby tones still play from the consumer (they depend on queue state after playback).
@ -135,7 +140,7 @@ On `docker compose down` or `make restart`, the server lets the currently-playin
- Explicit `cancel_speech()` kills pw-play + plays cancel tone; MCP disconnect lets playback finish
- Consumer directly awaits `play_audio()`; `cancel()` targets the consumer task with `_item_cancelled` flag
- `speak()`'s CancelledError handler does NOT cancel the consumer — only explicit cancel does
- Graceful shutdown: uvicorn waits `shutdown_timeout` for handlers, consumer finishes audio naturally, then lifespan runs `queue.stop()`
- Graceful shutdown is two-phase: 3s handler drain (fixed) + `shutdown_timeout` queue drain, both sequential within Docker's `stop_grace_period`
- Tones are non-fatal: if `pw-play` fails on a tone, speech still plays
- Orpheus uses llama-server (not Ollama) for 15x throughput via continuous batching
- SNAC decoder is lazy-loaded on first Orpheus call to reduce idle memory

View File

@ -3,7 +3,9 @@ services:
build: .
container_name: tts-mcp
restart: unless-stopped
stop_grace_period: 35s
# Must exceed: 3s handler drain + TTS_SHUTDOWN_TIMEOUT + 5s safety margin.
# Default: 3 + 30 + 5 = 38s. Increase if TTS_SHUTDOWN_TIMEOUT > 30.
stop_grace_period: 38s
env_file: .env
environment:
# Override for Docker networking (container DNS instead of IPs)

View File

@ -10,10 +10,15 @@ def main():
host=settings.host,
port=settings.port,
stateless_http=True,
# Override FastMCP's default timeout_graceful_shutdown=0 so uvicorn
# lets in-flight speak() calls finish before cancelling them. Must
# be shorter than Docker's stop_grace_period (35s) to avoid SIGKILL.
uvicorn_config={"timeout_graceful_shutdown": settings.shutdown_timeout},
# On SIGTERM, uvicorn drains HTTP handlers first (Phase 1), then runs
# lifespan shutdown where queue.stop() waits for the consumer (Phase 2).
# These phases are SEQUENTIAL and share Docker's stop_grace_period budget.
#
# Phase 1 (handler drain): 3s — speak() just re-raises CancelledError,
# it does not cancel the consumer (audio keeps playing).
# Phase 2 (queue.stop): shutdown_timeout — consumer finishes current audio.
# Docker budget: shutdown_timeout + 3s handler drain + 5s safety margin.
uvicorn_config={"timeout_graceful_shutdown": 3},
)

View File

@ -138,6 +138,18 @@ class SpeechQueue:
self._stopped = True
try:
if self._consumer_task and not self._consumer_task.done():
# Log what we're waiting for
if self._current:
elapsed = time.time() - self._current.enqueued_at
remaining = max(0, self._current.result.duration_seconds - elapsed)
print(
f"Speech queue: waiting for current audio "
f"(~{remaining:.0f}s remaining, budget {self._shutdown_timeout:.0f}s)",
file=sys.stderr,
)
else:
print("Speech queue: consumer idle, shutting down", file=sys.stderr)
# Consumer polls _stopped every 0.5s between items, so it will
# exit the while loop after finishing the current item.
try:
@ -151,7 +163,7 @@ class SpeechQueue:
)
except asyncio.TimeoutError:
print(
f"Speech queue: shutdown timeout ({self._shutdown_timeout}s) "
f"Speech queue: shutdown timeout ({self._shutdown_timeout:.0f}s) "
f"expired, force-cancelling consumer",
file=sys.stderr,
)

View File

@ -88,6 +88,10 @@ async def app_lifespan(server: FastMCP):
f" Voice identity: {identity_label}{announce_label}",
file=sys.stderr,
)
print(
f" Shutdown budget: 3s handler drain + {settings.shutdown_timeout:.0f}s queue drain + 5s safety",
file=sys.stderr,
)
try:
yield {