From a1775e9f5d6808c5a2b6fe8a82b1b09453abf16e Mon Sep 17 00:00:00 2001 From: byrongamatos Date: Fri, 10 Jul 2026 21:19:28 +0200 Subject: [PATCH 1/2] fix(ws_highway): swallow a mid-stream WebSocketDisconnect quietly MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Pre-existing (byte-identical to origin/main), flagged by CodeRabbit on #844: the outer try's only guard was `except Exception as e: log.exception("highway_ws unhandled error")`. The inner `except WebSocketDisconnect` covers ONLY the post-`ready` keep-alive loop, and the drum_tab/notation sends have their own localized guards — but the ~13 other streamed sends (beats, sections, notes, chords, anchors, …) fall through to the blanket handler. Since WebSocketDisconnect is an Exception subclass, a routine tab-close mid-load was logged as an error at whichever send was in flight. Fix: a dedicated `except WebSocketDisconnect: return` before the blanket handler, matching the two localized guards and the lib/ coding guideline. tests/test_ws_highway_disconnect.py drives highway_ws with a fake websocket that raises WebSocketDisconnect on the first streamed send (`loading`), over a real minimal sloppak. Negative-checked: removing the guard makes it fail (the disconnect is logged as `highway_ws unhandled error`); the fix passes. Uses a raw handler on `feedBack.server` rather than caplog, since configure_logging() reroutes that logger through structlog where caplog doesn't observe it. Full suite green. Closes the review thread on #844. Co-Authored-By: Claude Opus 4.8 (1M context) --- lib/routers/ws_highway.py | 7 ++ tests/test_ws_highway_disconnect.py | 106 ++++++++++++++++++++++++++++ 2 files changed, 113 insertions(+) create mode 100644 tests/test_ws_highway_disconnect.py diff --git a/lib/routers/ws_highway.py b/lib/routers/ws_highway.py index c420780b..9466f827 100644 --- a/lib/routers/ws_highway.py +++ b/lib/routers/ws_highway.py @@ -1036,6 +1036,13 @@ def _fill_scale_degree(wire: dict, n, t: float) -> None: except WebSocketDisconnect: pass + except WebSocketDisconnect: + # A client that navigates away / closes the tab mid-stream is routine, + # not an error. Without this, the disconnect falls through to the blanket + # handler below and logs `highway_ws unhandled error` for every send point + # (the inner guard only covers the post-`ready` keep-alive loop). Matches + # the two localized WebSocketDisconnect guards in the streaming body. + return except Exception as e: log.exception("highway_ws unhandled error for %s", filename) try: diff --git a/tests/test_ws_highway_disconnect.py b/tests/test_ws_highway_disconnect.py new file mode 100644 index 00000000..30ad39f9 --- /dev/null +++ b/tests/test_ws_highway_disconnect.py @@ -0,0 +1,106 @@ +"""A client that disconnects mid-stream is routine, not a logged error. + +The highway WS streams ~15 message batches before its keep-alive loop. A +disconnect during that streaming used to fall through to the blanket +`except Exception` and log `highway_ws unhandled error`. The dedicated +`except WebSocketDisconnect: return` makes it quiet. +""" + +import asyncio +import importlib +import json +import logging +import sys + +import pytest +import yaml +from fastapi import WebSocketDisconnect + + +def _write_sloppak(dlc_root): + pak = dlc_root / "disc.sloppak" + pak.mkdir(parents=True) + (pak / "arrangements").mkdir() + (pak / "arrangements" / "lead.json").write_text(json.dumps({ + "notes": [], "chords": [], "anchors": [], "handshapes": [], + "templates": [], "beats": [{"time": 0.0, "measure": 1}], + "sections": [{"name": "intro", "number": 1, "time": 0.0}], + })) + (pak / "manifest.yaml").write_text(yaml.safe_dump({ + "title": "Disc", "artist": "T", "album": "", "year": 2026, "duration": 10.0, + "arrangements": [{"id": "lead", "name": "Lead", "file": "arrangements/lead.json"}], + "stems": [], + }, sort_keys=False)) + return pak + + +class _DisconnectingWS: + """Accepts, then raises WebSocketDisconnect on the first streamed send — + i.e. a client that drops mid-stream.""" + def __init__(self): + self.sends = 0 + + async def accept(self): + pass + + async def send_json(self, data): + self.sends += 1 + raise WebSocketDisconnect(code=1001) + + async def receive_text(self): + raise WebSocketDisconnect(code=1001) + + async def close(self): + pass + + +@pytest.fixture() +def server(tmp_path, monkeypatch): + (tmp_path / "dlc").mkdir() + monkeypatch.setenv("CONFIG_DIR", str(tmp_path / "config")) + monkeypatch.setenv("DLC_DIR", str(tmp_path / "dlc")) + monkeypatch.setenv("FEEDBACK_SKIP_STARTUP_TASKS", "1") + sys.modules.pop("server", None) + mod = importlib.import_module("server") + yield mod, tmp_path / "dlc" + conn = getattr(getattr(mod, "meta_db", None), "conn", None) + if conn is not None: + getattr(mod, "_join_background_db_threads", lambda: None)() + conn.close() + sys.modules.pop("server", None) + + +class _Capture(logging.Handler): + def __init__(self): + super().__init__() + self.messages = [] + + def emit(self, record): + self.messages.append(record.getMessage()) + + +def test_midstream_disconnect_is_not_logged_as_error(server): + """The first streamed send (`loading`) raises WebSocketDisconnect; the + handler must return quietly, not log `highway_ws unhandled error`. + + A raw handler on `feedBack.server` is used rather than pytest's `caplog` + because `configure_logging()` (run at server import) reroutes that logger + through the structlog pipeline, which caplog's fixture doesn't observe. + """ + _server, dlc = server + _write_sloppak(dlc) + from routers.ws_highway import highway_ws + + cap = _Capture() + cap.setLevel(logging.ERROR) + lg = logging.getLogger("feedBack.server") + lg.addHandler(cap) + try: + ws = _DisconnectingWS() + asyncio.run(highway_ws(ws, "disc.sloppak", arrangement=0)) # must not raise + finally: + lg.removeHandler(cap) + + assert ws.sends >= 1, "handler never reached a streamed send" + unhandled = [m for m in cap.messages if "highway_ws unhandled error" in m] + assert not unhandled, f"disconnect logged as unhandled error: {unhandled}" From 0d66c016ff5db313c7f06bd8bd9869b422aed190 Mon Sep 17 00:00:00 2001 From: byrongamatos Date: Fri, 10 Jul 2026 21:26:16 +0200 Subject: [PATCH 2/2] =?UTF-8?q?test(ws=5Fhighway):=20assert=20streaming=20?= =?UTF-8?q?stops=20after=20disconnect=20(exactly=20one=20send)=20=E2=80=94?= =?UTF-8?q?=20CodeRabbit?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The stub now raises only on the first send and the test asserts ws.sends == 1, so a handler that caught the disconnect and kept streaming would fail. Still negative-checked: removing the guard fails the test. --- tests/test_ws_highway_disconnect.py | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/tests/test_ws_highway_disconnect.py b/tests/test_ws_highway_disconnect.py index 30ad39f9..3e97df0c 100644 --- a/tests/test_ws_highway_disconnect.py +++ b/tests/test_ws_highway_disconnect.py @@ -45,7 +45,11 @@ async def accept(self): async def send_json(self, data): self.sends += 1 - raise WebSocketDisconnect(code=1001) + # Raise only on the FIRST send. If the handler wrongly kept streaming + # after catching the disconnect, later sends would succeed and `sends` + # would climb past 1 — the exactly-one assertion catches that. + if self.sends == 1: + raise WebSocketDisconnect(code=1001) async def receive_text(self): raise WebSocketDisconnect(code=1001) @@ -101,6 +105,6 @@ def test_midstream_disconnect_is_not_logged_as_error(server): finally: lg.removeHandler(cap) - assert ws.sends >= 1, "handler never reached a streamed send" + assert ws.sends == 1, f"handler kept streaming after the disconnect ({ws.sends} sends)" unhandled = [m for m in cap.messages if "highway_ws unhandled error" in m] assert not unhandled, f"disconnect logged as unhandled error: {unhandled}"