Skip to content

Graceful shutdown unbounded: foyer close() runs outside stop-grace deadline → ~9-min redeploy stall #82

Description

@tonyalaribe

Summary

Graceful shutdown is effectively unbounded. The stop-grace deadline (TIMEFUSION_STOP_GRACE_SECS, default 50s) only bounds the PGWire/gRPC drain and BufferedWriteLayer::shutdown_by. The final Database::shutdown() — which calls foyer HybridCache::close() to flush the disk cache — has no timeout and never receives the deadline, so a slow foyer flush blocks process exit (and WAL-lock release) for minutes. Every redeploy that hits this is a ~10-minute outage.

Evidence (prod 2026-07-13 redeploy, outgoing instance)

  • 04:35:25 SIGTERM.
  • 04:35:49 object_store_cache: Closing Foyer caches... + foyer::hybrid::cache: flush all in-memory cached entries to disk on close bytes=377079339 (377 MB).
  • 8.5-min gap, no further log output.
  • 04:44:23 process exits; the incoming instance (spinning on WAL dir ...wal.lock is locked by another TimeFusion process; waiting... since 04:35:25) finally acquires the lock.

The 24s-in foyer marker proves the deadline-bounded phases (PGWire, gRPC, shutdown_by) had already completed — the 8.5 min was spent entirely in the unbounded db.shutdown().

Root cause

src/main.rs:437 calls db_for_shutdown.shutdown().await with no tokio::time::timeout and no shared deadline. Inside Database::shutdown() (src/database.rs:5296-5330) every await is unbounded; the overrunning one is cache.shutdown()FoyerObjectStoreCache::shutdownself.cache.close().await (src/object_store_cache.rs:362), foyer's flush-to-disk-on-close, which has no close budget (src/object_store_cache.rs:169-186). The WAL lock is held for process lifetime (src/wal.rs:1332-1336) and released only on exit, which main cannot reach until foyer close returns.

The deadline-bounded shutdown_by full-buffer flush (src/buffered_write_layer.rs:2155, timeout_at) is correct and is not the cause.

Bonus finding

TIMEFUSION_SHUTDOWN_TIMEOUT_SECS (=15 in prod) is read nowhere in the Rust source (grep → 0 refs). It's a phantom/no-op env var; operators believe shutdown is bounded to 15s but nothing reads it.

Proposed fix

  1. Cap the final DB shutdown: tokio::time::timeout(remaining_grace, db.shutdown()) at main.rs:437, log-and-proceed on elapse. Better: thread deadline into a Database::shutdown_by(deadline) so all inner awaits share one absolute budget (as BufferedWriteLayer already does).
  2. Bound foyer close specifically (object_store_cache.rs:362-363). The disk cache is a rebuildable read cache — abandoning an in-progress flush loses only cache warmth, never durable data. Prioritize releasing wal.lock.
  3. Remove or actually wire up the phantom TIMEFUSION_SHUTDOWN_TIMEOUT_SECS.

Severity / impact

High. Every redeploy risks a multi-minute stall: the outgoing instance holds wal.lock while foyer flushes, and the incoming instance blocks on lock acquisition the entire time (readiness stays TCP-green, masking it). Observed ~9 min with a 377 MB cache; larger caches / slower disk make it worse. Swarm StopGracePeriod=600s usually lets it finish just under SIGKILL, so it self-recovers — at the cost of a ~10-min ingest/query gap per deploy.

Key files: src/main.rs:437, src/database.rs:5296-5330, src/object_store_cache.rs:356-366, src/wal.rs:1332-1336.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions