From 0fb8f4ea92ef5da0f7e5ad48260e6f6bc4d50f2e Mon Sep 17 00:00:00 2001 From: ArthurBernard Date: Sun, 5 Jul 2026 11:14:43 +0200 Subject: [PATCH] fix: complete daemon teardown on Ctrl-C; quiet SSE shutdown cancellation start --serve died before its supervisor teardown ran because uvicorn 0.49's Server.serve() unconditionally re-raises the captured SIGINT/ SIGTERM (with the default disposition) right after serve() returns. _run_daemon now overrides the server's capture_signals with a no-op and owns the signal itself (there is no install_signal_handlers config flag on this uvicorn version), so its own finally (scheduler shutdown + supervisor.shutdown()) always completes. Separately, a connected dashboard/SSE client made every shutdown log a multi-screen CancelledError/anyio.WouldBlock traceback at ERROR level: uvicorn force-cancels the SSE connection past the graceful-shutdown timeout, and Starlette's StreamingResponse (uvicorn 0.49 is stuck on its older, task-group-based implementation) re-raises that unconverted. Both /api/events generators now end cleanly on cancellation (the merged one also cancels any outstanding per-iteration getter task), and a logging filter drops uvicorn's own "Exception in ASGI application" record for that specific, expected cancellation shape. Verified with a pty driver sending a genuine keyboard Ctrl-C against a connected SSE client: dashboard and start --serve both exit 0 in under 5s with their "stopped" banner and no ERROR-level traceback; headless start + SIGINT is unchanged. --- CHANGELOG.md | 6 + doc/dev/03-decisions.md | 48 ++++++ trading_bot/interfaces/api/app.py | 113 ++++++++++++++ trading_bot/interfaces/cli/main.py | 82 +++++++++- trading_bot/tests/interfaces/test_api.py | 143 ++++++++++++++++++ .../tests/interfaces/test_dashboard.py | 131 ++++++++++++++++ 6 files changed, 518 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 585f12d9..6cc40c49 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -64,6 +64,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 (shape-checked so an arbitrary value is never echoed into the form), and `/favicon.ico` is an open route (308 → `/static/favicon.svg`) so the probe never bounces through the auth redirect at all. +- **Clean Ctrl-C shutdown.** `start --serve`'s Ctrl-C/SIGTERM handling now + completes the supervisor teardown instead of the process dying mid-shutdown + (uvicorn 0.49's own signal capture re-raised the captured signal after + `serve()` returned, killing the process before the daemon's `finally` ran); + the dashboard's `/api/events` SSE stream also no longer spams an ERROR-level + cancellation traceback on every shutdown while a client holds it open. ### Deprecated diff --git a/doc/dev/03-decisions.md b/doc/dev/03-decisions.md index 7e6ce88c..0181ece8 100644 --- a/doc/dev/03-decisions.md +++ b/doc/dev/03-decisions.md @@ -6,6 +6,54 @@ rejected approaches as tombstones. --- +### 2026-07-05 Clean Ctrl-C shutdown: the daemon owns its signals; SSE cancellation ends the stream [accepted] +- **Choice**: two independent fixes, both in the shutdown path uvicorn/starlette + own by default. (1) `_run_daemon`'s `--serve` branch overrides the built + `uvicorn.Server` instance's `capture_signals` with a no-op context manager + (there is no public `install_signal_handlers` config flag on uvicorn 0.49) and + installs its own `SIGINT`/`SIGTERM` handlers on the running loop around + `await server.serve()`: first signal sets `server.should_exit = True` + (graceful — uvicorn's own main loop polls this regardless of who sets it), + second sets `server.force_exit = True`; the handlers are removed once + `serve()` returns. (2) both `/api/events` SSE generators in + `interfaces/api/app.py` catch `asyncio.CancelledError` around their streaming + loop and end the generator cleanly instead of letting it propagate (the merged + generator also explicitly cancels any outstanding per-iteration getter task on + the way out); additionally, a `logging.Filter` on the `uvicorn.error` logger + drops uvicorn's "Exception in ASGI application" record specifically when the + underlying exception is a plain `asyncio.CancelledError` — necessary because + the noisy traceback is *not* raised by our own generator code: it originates + in Starlette's `StreamingResponse.__call__` (an `anyio` task group racing + "stream the body" against "listen for disconnect", the code path uvicorn 0.49 + is stuck on since it declares ASGI `spec_version: "2.3"`, below the `2.4` + Starlette checks for its newer, single-await implementation), so no amount of + fixing our own generator's cancellation handling prevents uvicorn from logging + it. +- **Why**: uvicorn 0.49's `Server.serve()` unconditionally wraps itself in + `capture_signals()`, which restores the pre-`serve()` signal disposition and + **re-raises** the captured signal with that (default) disposition right after + `serve()` returns — killing the process *before* `_run_daemon`'s own `finally` + (scheduler shutdown + `supervisor.shutdown()`) could run, so a paper store's + pending writes were never drained and units weren't stopped cleanly on Ctrl-C. + Separately, operators reading a multi-screen `CancelledError`/`anyio.WouldBlock` + traceback on every shutdown while a dashboard tab was open mistook a routine, + timeout-bounded force-cancel (`_SHUTDOWN_GRACE_SECONDS = 3`, kept as-is; its + own "Cancel N running task(s)..." log line stays — it *is* useful signal) for + a crash. +- **Rejected alternatives**: passing `install_signal_handlers=False` to + `uvicorn.Config(...)` (the shape assumed going in) — that flag does not exist + in uvicorn 0.49's actual `Config`/`Server` API (confirmed against the + installed version; it raises `TypeError` at construction), so the + `capture_signals` override is the version-correct equivalent. Restructuring + `_install_hardening`'s two `@app.middleware("http")` handlers into raw ASGI + middleware (removing `BaseHTTPMiddleware`'s task/stream indirection entirely, + which independently reproduces the same traceback even with *no* custom + middleware registered, per direct testing against a bare FastAPI app) — would + also work and is more "correct" in spirit, but is a much larger, riskier + change for a shutdown-logging concern; the targeted logging filter achieves + the same operator-facing outcome (no ERROR-level traceback spam) without + touching request/response plumbing every endpoint relies on. + ### 2026-07-04 Display-only rounding, exact value on hover (PR #160) [accepted] - **Choice**: a single dependency-free `static/format.js` (the `tbFmt` namespace) owns every display transform — grouped/rounded money by quote currency diff --git a/trading_bot/interfaces/api/app.py b/trading_bot/interfaces/api/app.py index 91339bc5..b1f0f9c8 100644 --- a/trading_bot/interfaces/api/app.py +++ b/trading_bot/interfaces/api/app.py @@ -443,6 +443,82 @@ def _finite_or_none(value: float | None) -> float | None: } +class _SuppressGracefulShutdownCancellation(logging.Filter): + """Drop uvicorn's "Exception in ASGI application" record for an expected + graceful-shutdown cancellation — not a real application bug. + + Why this lives at the logging layer, not in a route + ----------------------------------------------------- + Every ``/api/events`` route below returns a plain + :class:`~starlette.responses.StreamingResponse`. uvicorn 0.49 declares ASGI + ``spec_version: "2.3"`` for HTTP (see + ``uvicorn/protocols/http/httptools_impl.py``), which is *below* the + ``(2, 4)`` threshold Starlette's own ``StreamingResponse.__call__`` checks + before picking its newer, single-await implementation — so under this + uvicorn version Starlette *always* falls back to its older code path: an + ``anyio`` task group racing "stream the body" against "listen for + disconnect" (``starlette/responses.py``). When + ``timeout_graceful_shutdown`` (:data:`_SHUTDOWN_GRACE_SECONDS`) elapses on a + still-open SSE connection, uvicorn force-cancels the per-connection task — + logging "Cancel N running task(s), timeout graceful shutdown exceeded" (a + legitimate, expected line, left alone). That cancellation lands *inside + Starlette's own task group*, which re-raises it unconverted all the way + back up to uvicorn's ``run_asgi``, which logs **any** exception escaping the + ASGI app — even a deliberate cancellation it just issued itself — as an + ERROR-level, multi-frame traceback ("Exception in ASGI application"). + Operators read that as a crash on every shutdown while a client holds + ``/api/events`` open, even though the SSE generators in this module (see + their own ``except asyncio.CancelledError`` handling) already end cleanly + the moment cancellation reaches *their* frame — the noisy traceback + originates in Starlette's own plumbing, which this module does not control, + so suppressing it has to happen at the logging layer instead. This filter + drops *only* that exact, expected shape — an :class:`asyncio.CancelledError` + reaching uvicorn's "Exception in ASGI application" log call — so a genuine + application exception (any other exception type, or a ``CancelledError`` + logged under a different message) is still logged normally. + + Matching on exception *type* alone (not also uvicorn's own cancel message, + e.g. "Task cancelled, timeout graceful shutdown exceeded") is deliberate: + with **two** stacked ``@app.middleware("http")`` handlers here (see + :func:`_install_hardening`), each ``BaseHTTPMiddleware`` layer's own nested + ``anyio`` task group can re-signal the cancellation through its *own* + cancel scope on the way back out, which — per ``anyio``'s cancel-scope + bookkeeping — can substitute a **fresh, message-less** + ``CancelledError()`` for the one uvicorn originally raised. The message is + the only thing lost; every step in the chain is still a plain + cancellation. Restricting the match to uvicorn's own "Exception in ASGI + application" message keeps this from ever catching an unrelated + ``uvicorn.error`` record. + """ + + _EXPECTED_MESSAGE_PREFIX = "Exception in ASGI application" + + def filter(self, record: logging.LogRecord) -> bool: + """Return ``False`` (drop) only for the expected shutdown cancellation.""" + if not record.exc_info: + return True + exc = record.exc_info[1] + is_expected = isinstance( + exc, asyncio.CancelledError + ) and record.getMessage().startswith(self._EXPECTED_MESSAGE_PREFIX) + return not is_expected + + +def _suppress_graceful_shutdown_cancellation_logs() -> None: + """Install :class:`_SuppressGracefulShutdownCancellation` on ``uvicorn.error`` once. + + Idempotent (checked by filter *type*), so calling this from every + :func:`create_app` / :func:`create_dashboard_app` build — including in + tests, which build many apps per process — never stacks up duplicate + filter instances. + """ + target = logging.getLogger("uvicorn.error") + if not any( + isinstance(f, _SuppressGracefulShutdownCancellation) for f in target.filters + ): + target.addFilter(_SuppressGracefulShutdownCancellation()) + + def _install_hardening(app: FastAPI) -> None: """Add the shared body-size cap + security-header middleware to ``app``. @@ -456,11 +532,17 @@ def _install_hardening(app: FastAPI) -> None: :data:`_SECURITY_HEADERS` (nosniff / anti-clickjacking / no-referrer), and every authed JSON body (``/api/*``) additionally gets ``Cache-Control: no-store`` so the live book is never cached by a browser or intermediary. + * **Quiet shutdown.** Installs + :class:`_SuppressGracefulShutdownCancellation` on the ``uvicorn.error`` + logger so a force-cancelled ``/api/events`` connection past + :data:`_SHUTDOWN_GRACE_SECONDS` doesn't spam an ERROR-level traceback for + what is an expected, controlled shutdown (see that class's docstring). Middleware runs outermost-first in registration order; the body cap is added last here so it runs **first** (it can reject before the header middleware even builds a response). """ + _suppress_graceful_shutdown_cancellation_logs() @app.middleware("http") async def _security_headers(request: Request, call_next: Any) -> Any: @@ -658,6 +740,17 @@ async def _generator() -> Any: yield f"data: {json.dumps(frame, default=_default)}\n\n" except asyncio.TimeoutError: yield ": heartbeat\n\n" + except asyncio.CancelledError: + # Server shutdown (the graceful-shutdown timeout force-cancels this + # task while it is suspended in the wait above) or the ASGI server + # tearing the connection down: either way the stream is over, which + # is the *correct* time for this generator to end — not an error. + # Left uncaught, this propagates as a bare CancelledError that + # uvicorn/starlette log as a scary ERROR-level traceback on every + # shutdown while a client holds this endpoint open; ending the + # generator cleanly here is the intended response to "server is + # going away", not a swallowed real failure. + pass finally: bus.remove_queue(queue) @@ -1925,6 +2018,10 @@ async def events(request: Request) -> StreamingResponse: async def _generator() -> Any: seen: set[str] = set() + # Tracks the current iteration's per-queue getter tasks so a + # cancellation between iterations (see the CancelledError handler + # below) can still cancel whichever ones are outstanding. + getters: list[asyncio.Task[Any]] = [] try: yield ": connected\n\n" if not queues: @@ -1950,6 +2047,7 @@ async def _generator() -> Any: ) for task in pending: task.cancel() + getters = [] if not done: yield ": heartbeat\n\n" continue @@ -1966,6 +2064,21 @@ async def _generator() -> Any: "ts": _epoch_ms(), } yield f"data: {json.dumps(frame, default=_default)}\n\n" + except asyncio.CancelledError: + # Server shutdown (the graceful-shutdown timeout force-cancels this + # task while a client holds the merged stream open) or the ASGI + # server tearing the connection down: the stream is over, which is + # the correct time for this generator to end, not an error. Any + # getter task still outstanding at the point of cancellation (e.g. + # cancelled mid-`asyncio.wait`, before the per-iteration cleanup + # above ran) is cancelled here too, so no bare queue.get() task is + # left dangling. Left uncaught, this propagates as a bare + # CancelledError that uvicorn/starlette log as a scary ERROR-level + # traceback on every shutdown while a client holds this endpoint + # open. + for task in getters: + if not task.done(): + task.cancel() finally: for bus, queue in zip(buses, queues, strict=True): bus.remove_queue(queue) diff --git a/trading_bot/interfaces/cli/main.py b/trading_bot/interfaces/cli/main.py index d4ccfce5..fb911f1b 100644 --- a/trading_bot/interfaces/cli/main.py +++ b/trading_bot/interfaces/cli/main.py @@ -770,14 +770,36 @@ async def _run_daemon( running units on an **interval** (or **cron**) via an ``apscheduler`` ``AsyncIOScheduler``. When ``serve`` is set, the control dashboard (:func:`~trading_bot.interfaces.api.create_control_app`) is served over the same - supervisor on ``host:port`` (loopback by default — it can change what trades), - and **uvicorn owns the signal** (Ctrl-C ends serve, then the daemon tears down); + supervisor on ``host:port`` (loopback by default — it can change what trades); headless, the daemon installs its own ``SIGINT``/``SIGTERM`` handlers. Each step is idempotent over unchanged data, so a tick that finds nothing to do trades nothing. The scheduler's cadence (next run time + trigger description) is wired into the served dashboard's ``/api/health`` via a ``schedule_info`` hook — the plain ``dashboard`` command has no scheduler, so its health always reports ``next_tick_ts``/``tick`` as ``null``. + + Signal ownership (``serve``) — **the daemon owns the signal, not uvicorn** + --------------------------------------------------------------------------- + uvicorn 0.49's ``Server.serve()`` unconditionally wraps its execution in a + ``capture_signals()`` context manager that installs its own ``SIGINT``/ + ``SIGTERM`` handler for the duration of ``serve()`` and, in its ``finally``, + restores the pre-``serve()`` signal disposition and **re-raises the captured + signal** (``signal.raise_signal``) so an embedding app's own handler gets a + chance to react. With nothing installed beforehand, the restored disposition + is Python's default one, so the re-raised signal kills the process outright — + *before* this function's ``finally`` (scheduler + supervisor teardown) gets a + chance to run. There is no public config flag to opt out of this (the older + ``install_signal_handlers`` flag no longer exists), so the *instance's* + ``capture_signals`` is overridden with a no-op context manager, disabling + that capture/re-raise entirely; this function then installs its *own* + ``SIGINT``/``SIGTERM`` handlers on the running loop around + ``await server.serve()``: the first signal asks uvicorn to exit gracefully + (``server.should_exit = True`` — uvicorn's main loop polls this regardless of + who sets it), a second forces it (``server.force_exit = True``); the handlers + are removed in a ``finally`` once ``serve()`` returns. With uvicorn's own + signal capture disabled there is nothing left to re-raise, so this function's + outer ``finally`` (scheduler shutdown + ``supervisor.shutdown()``) always runs + to completion and the process exits normally. """ from apscheduler.schedulers.asyncio import AsyncIOScheduler from apscheduler.triggers.cron import CronTrigger @@ -858,11 +880,54 @@ def _schedule_info() -> dict[str, Any]: timeout_graceful_shutdown=_SHUTDOWN_GRACE_SECONDS, ) ) + # uvicorn 0.49 has no public switch to opt out of its own signal + # handling (the older `install_signal_handlers` config flag is gone): + # `Server.serve()` unconditionally wraps itself in + # `with self.capture_signals(): ...`, which installs `self.handle_exit` + # via raw `signal.signal()`, and — once `serve()` returns — restores + # the pre-serve() disposition and **re-raises the captured signal** + # (`signal.raise_signal`) so an embedding app's own handler can react. + # With nothing installed beforehand that restored disposition is + # Python's default one, so the re-raised SIGINT/SIGTERM kills the + # process outright — before this function's `finally` (scheduler + + # supervisor teardown) can run. Overriding the *instance's* + # `capture_signals` with a no-op context manager disables that + # capture/re-raise entirely, so the daemon below is the only thing + # that ever touches SIGINT/SIGTERM on this path (see the docstring's + # "Signal ownership" note). + server.capture_signals = contextlib.nullcontext # type: ignore[method-assign,assignment] _console.print( f"[green]control dashboard[/green] on http://{host}:{port}" " — Ctrl-C to stop" ) - await server.serve() # uvicorn owns SIGINT; blocks until Ctrl-C + + loop = asyncio.get_running_loop() + graceful_requested = False + + def _on_shutdown_signal() -> None: + # First signal: ask uvicorn to drain and exit gracefully (subject + # to timeout_graceful_shutdown; uvicorn's main loop polls + # `should_exit` regardless of how it was set). A second signal + # forces an immediate exit for an operator who really wants out + # now — the same should_exit/force_exit semantics uvicorn's own + # (now-disabled) handler would have applied. + nonlocal graceful_requested + if not graceful_requested: + graceful_requested = True + server.should_exit = True + else: + server.force_exit = True + + installed_signals: list[signal.Signals] = [] + for sig in (signal.SIGINT, signal.SIGTERM): + with contextlib.suppress(NotImplementedError, RuntimeError): + loop.add_signal_handler(sig, _on_shutdown_signal) + installed_signals.append(sig) + try: + await server.serve() # the daemon owns the signal; blocks until stopped + finally: + for sig in installed_signals: + loop.remove_signal_handler(sig) else: stop = asyncio.Event() loop = asyncio.get_running_loop() @@ -1065,8 +1130,15 @@ def dashboard( daemon's ``start`` steps strategies on a tick; the dashboard just serves the restored + controllable units), so a plain ``uvicorn.run`` inside ``try/finally`` is the whole loop — we deliberately do **not** also register a competing - ``loop.add_signal_handler(SIGINT, …)`` (that override is what makes - ``start --serve`` feel unquittable). + ``loop.add_signal_handler(SIGINT, …)`` here (an *additional* handler racing + uvicorn's own is what used to make a plain ``uvicorn.run``/``server.serve()`` + feel unquittable, needing a second Ctrl-C). ``start --serve`` no longer has + that problem either — it now disables uvicorn's own signal capture (its + ``Server.capture_signals`` is overridden to a no-op) and installs the *only* + handler itself, so there is nothing left to compete with (see + ``_run_daemon``'s "Signal ownership" docstring note for why: uvicorn 0.49 + otherwise re-raises the captured signal after ``serve()`` returns, killing + the process before its teardown ``finally`` runs). """ import uvicorn diff --git a/trading_bot/tests/interfaces/test_api.py b/trading_bot/tests/interfaces/test_api.py index f342f086..78dbd837 100644 --- a/trading_bot/tests/interfaces/test_api.py +++ b/trading_bot/tests/interfaces/test_api.py @@ -24,6 +24,7 @@ import asyncio import json +import logging from decimal import Decimal from typing import Any @@ -351,6 +352,54 @@ async def test_events_stream_delivers_fill_event_and_removes_queue( assert len(bus._queues) == before +async def test_events_stream_ends_cleanly_on_cancellation(engine: Engine) -> None: + """Cancelling the generator's task (server shutdown) ends the stream cleanly. + + Mirrors what uvicorn's graceful-shutdown timeout does to a connected SSE + client: the task driving the generator is force-cancelled while it is + suspended waiting on the queue. The generator must convert that + ``CancelledError`` into a clean end-of-stream (``StopAsyncIteration``, the + normal "no more values" signal for an async generator) rather than letting + the ``CancelledError`` propagate — which is what used to make uvicorn log a + scary ERROR-level traceback on every shutdown while a client held this + endpoint open. The bus queue must still be unregistered (the ``finally`` + is unaffected). + """ + app = create_app(engine) + bus = engine.bus + before = len(bus._queues) + + scope = { + "type": "http", + "method": "GET", + "path": "/api/events", + "headers": [], + "query_string": b"", + "app": app, + } + request = Request(scope, _never_disconnect) + response = await _events_route(app)(request) + frames = response.body_iterator + + first = await frames.__anext__() + assert first.startswith(":") + assert len(bus._queues) == before + 1 + + # Cancel the task while it is suspended awaiting the next frame (the queue + # has nothing queued, so it is parked inside `asyncio.wait_for(queue.get(), + # ...)` — exactly where a real shutdown-time cancellation would land). + task = asyncio.ensure_future(frames.__anext__()) + await asyncio.sleep(0) # let the task actually start awaiting the queue + task.cancel() + + with pytest.raises(StopAsyncIteration): + await task + assert not task.cancelled() # the cancellation was converted, not propagated + + # The `finally` still ran: the queue is unregistered like any other close. + assert len(bus._queues) == before + + # --- no-mutation: the API never places or cancels an order ----------------- # @@ -423,6 +472,100 @@ def test_event_dict_serializes_each_event_type_with_string_money() -> None: assert log_payload == {"type": "log", "message": "hi", "level": "warning"} +def _log_record(*, msg: str, exc: BaseException | None) -> logging.LogRecord: + """Build a bare ``LogRecord`` carrying ``exc`` as its ``exc_info`` (or none).""" + exc_info = (type(exc), exc, exc.__traceback__) if exc is not None else None + return logging.LogRecord( + name="uvicorn.error", + level=logging.ERROR, + pathname=__file__, + lineno=1, + msg=msg, + args=(), + exc_info=exc_info, + ) + + +def test_graceful_shutdown_cancellation_filter_drops_only_the_expected_shape() -> None: + """The uvicorn.error filter drops a shutdown CancelledError, keeps real errors. + + Regression test for the Ctrl-C quiet-shutdown fix: uvicorn 0.49 logs *any* + exception escaping the ASGI app as an ERROR "Exception in ASGI application" + record — including the deliberate ``CancelledError`` it raises itself when + force-cancelling a still-open SSE connection past the graceful-shutdown + timeout. The filter must drop *that* shape (regardless of the exception's + message — see the class docstring on why nested ``BaseHTTPMiddleware`` + task groups can strip it) while leaving a genuine application error, or a + ``CancelledError`` logged under an unrelated message, alone. + """ + from trading_bot.interfaces.api.app import _SuppressGracefulShutdownCancellation + + carveout = _SuppressGracefulShutdownCancellation() + + # Dropped: a CancelledError (message-bearing or not) under uvicorn's own + # "Exception in ASGI application" message. + assert ( + carveout.filter( + _log_record( + msg="Exception in ASGI application", + exc=asyncio.CancelledError( + "Task cancelled, timeout graceful shutdown exceeded" + ), + ) + ) + is False + ) + assert ( + carveout.filter( + _log_record( + msg="Exception in ASGI application", exc=asyncio.CancelledError() + ) + ) + is False + ) + + # Kept: a real bug under the same message. + assert ( + carveout.filter( + _log_record(msg="Exception in ASGI application", exc=ValueError("boom")) + ) + is True + ) + # Kept: a CancelledError logged under a different, unrelated message. + assert ( + carveout.filter( + _log_record(msg="some other message", exc=asyncio.CancelledError()) + ) + is True + ) + # Kept: no exc_info at all. + assert carveout.filter(_log_record(msg="plain info line", exc=None)) is True + + +def test_graceful_shutdown_cancellation_filter_installs_once_per_process() -> None: + """Building an app repeatedly never stacks up duplicate filter instances. + + ``create_app``/``create_dashboard_app`` install the filter on the shared, + process-wide ``uvicorn.error`` logger every time they build an app (tests + build many); the installer must stay idempotent. + """ + from trading_bot.interfaces.api.app import ( + _suppress_graceful_shutdown_cancellation_logs, + _SuppressGracefulShutdownCancellation, + ) + + target = logging.getLogger("uvicorn.error") + before = sum( + isinstance(f, _SuppressGracefulShutdownCancellation) for f in target.filters + ) + _suppress_graceful_shutdown_cancellation_logs() + _suppress_graceful_shutdown_cancellation_logs() + after = sum( + isinstance(f, _SuppressGracefulShutdownCancellation) for f in target.filters + ) + assert after == max(before, 1) + + def test_kpi_endpoint_stays_robust_over_a_profitable_curve() -> None: """``/api/kpi`` never 500s even when fynance can/can't define a ratio. diff --git a/trading_bot/tests/interfaces/test_dashboard.py b/trading_bot/tests/interfaces/test_dashboard.py index 425560eb..6b6f0690 100644 --- a/trading_bot/tests/interfaces/test_dashboard.py +++ b/trading_bot/tests/interfaces/test_dashboard.py @@ -1104,6 +1104,62 @@ async def test_events_stream_merges_and_yields_a_fill() -> None: assert [len(b._queues) for b in buses] == before # noqa: SLF001 +async def test_events_stream_ends_cleanly_on_cancellation() -> None: + """Cancelling the merged generator's task (server shutdown) ends it cleanly. + + Mirrors what uvicorn's graceful-shutdown timeout does to a connected SSE + client: the task driving the generator is force-cancelled while it is + suspended in ``asyncio.wait`` on the per-unit getter tasks. The generator + must convert that ``CancelledError`` into a clean end-of-stream + (``StopAsyncIteration``) rather than letting it propagate — which is what + used to make uvicorn log a scary ERROR-level traceback on every shutdown + while a dashboard client held this endpoint open — and every outstanding + per-iteration getter task plus every bus queue must still be cleaned up. + """ + import asyncio + + from fastapi import Request + + sup = StrategySupervisor(_two_venue_config(), dccd_client=_two_venue_client()) + await sup.start("btc-kraken") + await sup.start("eth-binance") + app = create_dashboard_app(sup) + buses = [sup._units[n].engine.bus for n in ("btc-kraken", "eth-binance")] # noqa: SLF001 + before = [len(b._queues) for b in buses] # noqa: SLF001 + + scope = { + "type": "http", + "method": "GET", + "path": "/api/events", + "headers": [], + "query_string": b"", + "app": app, + } + request = Request(scope, _never_disconnect) + response = await _events_route(app)(request) # type: ignore[operator] + frames = response.body_iterator + + first = await frames.__anext__() + assert first.startswith(":") + assert [len(b._queues) for b in buses] == [n + 1 for n in before] # noqa: SLF001 + + # Cancel the task while it is suspended in `asyncio.wait(getters, ...)` (no + # unit has emitted anything, so it is parked there — exactly where a real + # shutdown-time cancellation would land). + task = asyncio.ensure_future(frames.__anext__()) + await asyncio.sleep(0) # let the task actually start awaiting the getters + task.cancel() + + with pytest.raises(StopAsyncIteration): + await task + assert not task.cancelled() # the cancellation was converted, not propagated + + # The `finally` still ran: every bus queue is unregistered like any other + # close, and no getter task is left dangling (no "was destroyed but it is + # pending" warning — pytest-asyncio would otherwise surface it). + assert [len(b._queues) for b in buses] == before # noqa: SLF001 + + # --- strategy control (list + start/stop/mode, the live gate) -------------- # @@ -2169,6 +2225,81 @@ async def serve(self) -> None: assert health["tick"] == "every 0.05s" +async def test_start_serve_disables_uvicorn_signal_capture_and_owns_shutdown( + monkeypatch: pytest.MonkeyPatch, +) -> None: + """`start --serve` disables uvicorn's own signal capture and owns Ctrl-C itself. + + Regression test for the "Ctrl-C loses the teardown" bug: uvicorn 0.49's + ``Server.serve()`` unconditionally wraps itself in ``capture_signals()``, + which restores the pre-``serve()`` signal disposition and **re-raises** the + captured SIGINT/SIGTERM right after ``serve()`` returns — killing the + process before ``_run_daemon``'s own ``finally`` (scheduler + supervisor + teardown) can run. ``_run_daemon`` works around this (there is no public + ``install_signal_handlers`` config flag on this uvicorn version) by + overriding the server instance's ``capture_signals`` with a no-op context + manager and installing its own loop-level SIGINT/SIGTERM handlers around + ``await server.serve()``. This proves both halves: the override is applied, + and the daemon's own handlers are the ones registered *while* serving — + then removed once ``serve()`` returns. The end-to-end "the process actually + survives a real Ctrl-C and completes its teardown" claim is verified + separately by the pty-driver check (a unit test cannot deliver a real OS + signal to itself safely). + """ + import asyncio + import contextlib + import signal + + import trading_bot.interfaces.api as api_pkg + + monkeypatch.setattr(api_pkg, "create_dashboard_app", lambda sup, **kw: object()) + + built: dict[str, object] = {} + ready = asyncio.Event() + release = asyncio.Event() + installed_during_serve: set[int] = set() + + class _FakeServer: + def __init__(self, config: object) -> None: + self.config = config + self.should_exit = False + self.force_exit = False + built["server"] = self + + async def serve(self) -> None: + loop = asyncio.get_running_loop() + installed_during_serve.update(loop._signal_handlers) # noqa: SLF001 + ready.set() + await release.wait() + + import uvicorn + + monkeypatch.setattr(uvicorn, "Server", _FakeServer) + monkeypatch.setattr(uvicorn, "Config", lambda *a, **k: object()) + + from trading_bot.interfaces.cli.main import _run_daemon + + task = asyncio.ensure_future( + _run_daemon(AppConfig(), interval=0.05, cron=None, serve=True) + ) + await ready.wait() + + # The daemon's own handlers are installed WHILE serving — the exact window + # uvicorn 0.49 would otherwise own via its own (now-disabled) capture. + assert {signal.SIGINT, signal.SIGTERM} <= installed_during_serve + # uvicorn's own capture/re-raise is disabled on this server instance. + assert built["server"].capture_signals is contextlib.nullcontext # type: ignore[attr-defined] + + release.set() + await task + + # Removed again once `serve()` returned — nothing left registered, so a + # later real signal has exactly one handler to reach: the OS default. + loop = asyncio.get_running_loop() + assert signal.SIGINT not in loop._signal_handlers # noqa: SLF001 + assert signal.SIGTERM not in loop._signal_handlers # noqa: SLF001 + + # --- web hardening (audit wave 3: I-4, I-6, I-7, I-9, I-10, I-11, I-13) ----- #