From 7b75d03791dc3ddb32e8ed67c2309456af6e0d15 Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Mon, 19 Oct 2026 21:17:46 +0100 Subject: [PATCH 1/6] Security quick wins: admin-gate show deletion, debug off by default, non-root Docker, size limits Co-Authored-By: Claude Sonnet 5.5 --- Dockerfile | 8 +- README.md | 2 + client-v3/README.md | 2 +- server/README.md | 2 + server/controllers/api/v1/show/shows.py | 2 + server/digi_server/app_server.py | 11 +++ server/main.py | 12 ++- .../controllers/api/v1/show/test_shows.py | 27 ++++++ .../test/digi_server/test_server_hardening.py | 83 +++++++++++++++++++ 9 files changed, 141 insertions(+), 8 deletions(-) create mode 100644 server/test/digi_server/test_server_hardening.py diff --git a/Dockerfile b/Dockerfile index 5d693dce2..7e3997300 100644 --- a/Dockerfile +++ b/Dockerfile @@ -30,13 +30,13 @@ FROM python:3.13-bookworm COPY /server/requirements.txt ./requirements.txt RUN pip install -r requirements.txt -RUN apt update -RUN apt install -y nano - COPY /server /server COPY --from=build_v2 /server/static /server/static COPY --from=build_v3 /server/static /server/static WORKDIR /server -RUN mkdir conf +RUN useradd --system --create-home --uid 1000 digiscript \ + && mkdir -p conf \ + && chown -R digiscript:digiscript /server/conf +USER digiscript EXPOSE 8080 ENTRYPOINT ["python3", "main.py"] diff --git a/README.md b/README.md index a4ae9b7d5..01dacc647 100644 --- a/README.md +++ b/README.md @@ -110,6 +110,8 @@ python3 main.py The server will be available at `http://localhost:8080` +The server runs in production mode by default. When developing (for example with the `client-v3` Vite dev server), start it with `python3 main.py --debug` to enable autoreload and accept WebSocket connections from other origins. Never use `--debug` on a deployed server. + ### First Launch Setup On first launch, DigiScript will prompt you to create an administrator user. From there, you can create shows, configure users, and begin building your production. diff --git a/client-v3/README.md b/client-v3/README.md index e929a4803..49e6717a4 100644 --- a/client-v3/README.md +++ b/client-v3/README.md @@ -12,7 +12,7 @@ pnpm install pnpm run dev ``` -The dev server starts at `http://localhost:5173` and proxies API requests to `http://localhost:8080`. +The dev server starts at `http://localhost:5173` and proxies API requests to `http://localhost:8080`. Run the backend with `python3 main.py --debug` while developing. ### Compiles and minifies for production ``` diff --git a/server/README.md b/server/README.md index 4c16b6a7f..5e882f882 100644 --- a/server/README.md +++ b/server/README.md @@ -10,6 +10,8 @@ pip install -r requirements.txt python3 ./main.py ``` +Pass `--debug` for development (autoreload, relaxed WebSocket origin checks). It is off by default and must not be used on a deployed server. + This requires that the client has been build first in order to server the static files ## Project Structure diff --git a/server/controllers/api/v1/show/shows.py b/server/controllers/api/v1/show/shows.py index 6c295714e..3e38e236b 100644 --- a/server/controllers/api/v1/show/shows.py +++ b/server/controllers/api/v1/show/shows.py @@ -244,6 +244,8 @@ async def patch(self): self.set_status(404) await self.finish({"message": ERROR_SHOW_NOT_FOUND}) + @api_authenticated + @require_admin @requires_show @no_live_session async def delete(self): diff --git a/server/digi_server/app_server.py b/server/digi_server/app_server.py index f80b0952a..fc98008a6 100644 --- a/server/digi_server/app_server.py +++ b/server/digi_server/app_server.py @@ -47,6 +47,14 @@ from utils.web.route import Route +# Largest HTTP request body accepted by the server (passed to ``listen`` in +# ``main.py``). Legitimate payloads are JSON well under this size. +MAX_BODY_SIZE = 10 * 1024 * 1024 +# Largest single WebSocket message accepted: bigger than any control message, +# with headroom for Yjs document syncs. +MAX_WEBSOCKET_MESSAGE_SIZE = 16 * 1024 * 1024 + + class DigiScriptServer(PrometheusMixIn, Application): def __init__( self, @@ -331,8 +339,11 @@ class AlembicVersion(self._db.Model): super().__init__( handlers=handlers, debug=debug, + # Never return stack traces to clients, even in debug mode. + serve_traceback=False, db=self._db, websocket_ping_interval=5, + websocket_max_message_size=MAX_WEBSOCKET_MESSAGE_SIZE, cookie_secret=self._get_cookie_secret(), login_url="/login", ) diff --git a/server/main.py b/server/main.py index 80e8994d9..6eaef6b76 100755 --- a/server/main.py +++ b/server/main.py @@ -31,14 +31,20 @@ def ensure_writable_db_path(path): return path -from digi_server.app_server import DigiScriptServer +from digi_server.app_server import MAX_BODY_SIZE, DigiScriptServer from digi_server.logger import add_logging_level, get_logger add_logging_level("TRACE", logging.DEBUG - 5) get_logger().setLevel(logging.DEBUG) -define("debug", type=bool, default=not IS_FROZEN, help="auto reload") +define( + "debug", + type=bool, + default=False, + help="Development mode: autoreload, relaxed WebSocket origin checks. " + "Never enable on a deployed server.", +) define("port", type=int, default=8080, help="port to listen on") define("settings_path", type=str, default=None, help="Path to settings JSON file") define("skip_migrations", type=bool, default=False, help="skip database migrations") @@ -123,7 +129,7 @@ def patched_define( ) await app.configure() - app.listen(options.port) + app.listen(options.port, max_body_size=MAX_BODY_SIZE) get_logger().info(f"Listening on port: {options.port}") if options.debug: get_logger().warning("Running in debug mode") diff --git a/server/test/controllers/api/v1/show/test_shows.py b/server/test/controllers/api/v1/show/test_shows.py index be77ddc43..6b8e27700 100644 --- a/server/test/controllers/api/v1/show/test_shows.py +++ b/server/test/controllers/api/v1/show/test_shows.py @@ -420,6 +420,33 @@ def test_delete_show_cleans_up_rbac_mapping_rows(self): " the script", ) + def test_delete_show_unauthenticated(self): + """An unauthenticated request cannot delete a show.""" + show_b_id = self._create_show() + response = self.fetch( + f"/api/v1/show?id={show_b_id}", + method="DELETE", + allow_nonstandard_methods=True, + ) + self.assertEqual(401, response.code) + with self._app.get_db().sessionmaker() as session: + self.assertIsNotNone(session.get(Show, show_b_id)) + + def test_delete_show_non_admin(self): + """A logged-in non-admin cannot delete a show.""" + show_b_id = self._create_show() + with self._app.get_db().sessionmaker() as session: + user = User(username="regular", is_admin=False, password="test") + session.add(user) + session.flush() + user_id = user.id + session.commit() + token = self._app.jwt_service.create_access_token({"user_id": user_id}) + response = self._delete(show_b_id, token=token) + self.assertIn(response.code, (401, 403)) + with self._app.get_db().sessionmaker() as session: + self.assertIsNotNone(session.get(Show, show_b_id)) + def test_delete_currently_loaded_show(self): """Attempting to delete the currently loaded show returns 400.""" response = self._delete(self.show_a_id) diff --git a/server/test/digi_server/test_server_hardening.py b/server/test/digi_server/test_server_hardening.py new file mode 100644 index 000000000..3e61eac83 --- /dev/null +++ b/server/test/digi_server/test_server_hardening.py @@ -0,0 +1,83 @@ +import ast +from pathlib import Path + +from tornado.httpclient import HTTPRequest +from tornado.httpserver import HTTPServer +from tornado.testing import bind_unused_port, gen_test +from tornado.websocket import WebSocketClosedError, websocket_connect + +from digi_server.app_server import MAX_BODY_SIZE, MAX_WEBSOCKET_MESSAGE_SIZE +from test.conftest import DigiScriptTestCase + + +class TestServerHardening(DigiScriptTestCase): + def test_debug_option_defaults_to_off(self): + """Debug mode must be opt-in via ``--debug``.""" + tree = ast.parse( + (Path(__file__).parents[2] / "main.py").read_text(encoding="utf-8") + ) + defaults = [ + kw.value.value + for node in ast.walk(tree) + if isinstance(node, ast.Call) + and getattr(node.func, "id", None) == "define" + and node.args + and getattr(node.args[0], "value", None) == "debug" + for kw in node.keywords + if kw.arg == "default" + ] + self.assertEqual([False], defaults) + + def test_tracebacks_not_served_in_debug_mode(self): + """Even with debug=True (as in the test app) no traceback is returned.""" + self.assertTrue(self._app.settings["debug"]) + self.assertFalse(self._app.settings["serve_traceback"]) + response = self.fetch( + "/api/v1/auth/login", + method="POST", + body="{not valid json", + ) + self.assertGreaterEqual(response.code, 400) + self.assertNotIn(b"Traceback", response.body) + self.assertNotIn(b".py", response.body) + + @gen_test + async def test_oversized_http_body_rejected(self): + """The production HTTP server refuses bodies above ``MAX_BODY_SIZE``.""" + sock, port = bind_unused_port() + server = HTTPServer(self._app, max_body_size=MAX_BODY_SIZE) + server.add_sockets([sock]) + try: + request = HTTPRequest( + f"http://127.0.0.1:{port}/api/v1/auth/login", + method="POST", + body="x" * (MAX_BODY_SIZE + 1024), + ) + # The server rejects the request while it is still being sent, so + # the client sees either an error response or a dropped connection. + try: + response = await self.http_client.fetch(request, raise_error=False) + self.assertGreaterEqual(response.code, 400) + except OSError: + pass + finally: + server.stop() + sock.close() + + @gen_test + async def test_oversized_websocket_message_closes_connection(self): + """A WebSocket message above the configured cap terminates the socket.""" + limit = self._app.settings["websocket_max_message_size"] + self.assertEqual(MAX_WEBSOCKET_MESSAGE_SIZE, limit) + conn = await websocket_connect( + f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" + ) + try: + await conn.write_message("x" * (limit + 1024)) + except WebSocketClosedError: + pass + # Drain any greeting messages; the server then closes the connection. + message = await conn.read_message() + while message is not None: + message = await conn.read_message() + self.assertIsNone(message) From 61e8e3614012e9cc52841b463008e00ef56eb937 Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Mon, 19 Oct 2026 23:27:42 +0100 Subject: [PATCH 2/6] Add Docker entrypoint upgrade path, measured configurable size limits with logging, 1009 backoff Co-Authored-By: Claude Sonnet 5.5 --- Dockerfile | 10 ++- README.md | 24 ++++++ .../useWebSocket.closeTooBig.test.ts | 63 ++++++++++++++ client-v3/src/composables/useWebSocket.ts | 14 +++- docker-entrypoint.sh | 27 ++++++ server/controllers/ws_controller.py | 8 ++ server/digi_server/app_server.py | 15 ++-- server/main.py | 25 +++++- server/test/controllers/test_ws_controller.py | 25 +++++- server/test/digi_server/test_digi_server.py | 46 ++++++++++ .../test/digi_server/test_server_hardening.py | 83 ------------------- server/test/utils/web/test_size_limits.py | 43 ++++++++++ server/utils/web/size_limits.py | 75 +++++++++++++++++ 13 files changed, 360 insertions(+), 98 deletions(-) create mode 100644 client-v3/src/composables/useWebSocket.closeTooBig.test.ts create mode 100755 docker-entrypoint.sh delete mode 100644 server/test/digi_server/test_server_hardening.py create mode 100644 server/test/utils/web/test_size_limits.py create mode 100644 server/utils/web/size_limits.py diff --git a/Dockerfile b/Dockerfile index 7e3997300..72d701231 100644 --- a/Dockerfile +++ b/Dockerfile @@ -27,6 +27,10 @@ RUN pnpm run build FROM python:3.13-bookworm +RUN apt-get update \ + && apt-get install -y --no-install-recommends gosu \ + && rm -rf /var/lib/apt/lists/* + COPY /server/requirements.txt ./requirements.txt RUN pip install -r requirements.txt @@ -37,6 +41,8 @@ WORKDIR /server RUN useradd --system --create-home --uid 1000 digiscript \ && mkdir -p conf \ && chown -R digiscript:digiscript /server/conf -USER digiscript +COPY docker-entrypoint.sh /usr/local/bin/docker-entrypoint.sh EXPOSE 8080 -ENTRYPOINT ["python3", "main.py"] +# Starts as root only to fix ownership of existing volumes, then drops to the +# digiscript user (see docker-entrypoint.sh). +ENTRYPOINT ["docker-entrypoint.sh"] diff --git a/README.md b/README.md index 01dacc647..22c0d149b 100644 --- a/README.md +++ b/README.md @@ -86,6 +86,30 @@ docker-compose up -d DigiScript will be available at `http://localhost:8080` +**Upgrading from an older image:** the container now runs the server as an unprivileged `digiscript` +user. No manual steps are needed: on start, the entrypoint (`docker-entrypoint.sh`) runs as root, +fixes the ownership of an existing `/server/conf` volume or bind mount if it is still root-owned +(a one-time `chown`, skipped when ownership is already correct), then drops privileges. If you start +the container with `--user`/`user:` the entrypoint skips the ownership fix, so the mounted directory +must already be writable by that user. + +### Server options + +Pass these to `python3 main.py` (or append them to the container command / compose `command:`): + +| Option | Default | Purpose | +|--------|---------|---------| +| `--debug` | off | Development only: autoreload and relaxed WebSocket origin checks | +| `--max_body_size_mb` | 5 | Largest accepted HTTP request body, in MiB | +| `--max_ws_message_size_mb` | 64 | Largest accepted single WebSocket message, in MiB | + +The defaults were derived from a 450 page / 18,000 line script: the largest normal REST request is +one page of lines (about 17 KiB), and the largest WebSocket frame is a base64-encoded collaborative +editing update (a rewrite touching every line is under 1 MiB; inserting an entire 450 page script in +one go is about 14 MiB). A request over the HTTP limit is refused and an over-sized WebSocket message +closes the connection (close code 1009); both log a warning naming the limit and the client address. +Raise the limits and restart the server if you legitimately hit them. + ### Manual Installation #### Client diff --git a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts new file mode 100644 index 000000000..d2abd06bf --- /dev/null +++ b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts @@ -0,0 +1,63 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; +import { createPinia, setActivePinia } from 'pinia'; +import { useWebSocket } from './useWebSocket'; +import { toast } from '@/js/toast'; + +// Close code 1009 (message too big) must back off instead of reconnecting at the minimum +// delay forever. + +vi.mock('@/router', () => ({ default: { currentRoute: { value: { path: '/' } }, push: vi.fn() } })); +vi.mock('@/js/toast', () => ({ + toast: { info: vi.fn(), error: vi.fn(), success: vi.fn() }, +})); + +class FakeWebSocket { + static OPEN = 1; + static CONNECTING = 0; + static instances: FakeWebSocket[] = []; + readyState = 3; + onopen: (() => void) | null = null; + onmessage: ((e: { data: string }) => void) | null = null; + onclose: ((e?: { code: number }) => void) | null = null; + onerror: (() => void) | null = null; + + constructor() { + FakeWebSocket.instances.push(this); + } + + send(): void {} +} + +describe('close code 1009', () => { + beforeEach(() => { + FakeWebSocket.instances = []; + vi.useFakeTimers(); + vi.stubGlobal('WebSocket', FakeWebSocket); + setActivePinia(createPinia()); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.unstubAllGlobals(); + }); + + it('notifies the user once and backs off between reconnects', () => { + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + expect(toast.error).toHaveBeenCalledTimes(1); + + // First reconnect delay is 2s (1s * 2^1): nothing after 1.5s, a new socket after 2s. + vi.advanceTimersByTime(1500); + expect(FakeWebSocket.instances).toHaveLength(1); + vi.advanceTimersByTime(600); + expect(FakeWebSocket.instances).toHaveLength(2); + + FakeWebSocket.instances[1].onclose?.({ code: 1009 }); + expect(toast.error).toHaveBeenCalledTimes(1); + // Second delay doubles to 4s. + vi.advanceTimersByTime(3500); + expect(FakeWebSocket.instances).toHaveLength(2); + vi.advanceTimersByTime(600); + expect(FakeWebSocket.instances).toHaveLength(3); + }); +}); diff --git a/client-v3/src/composables/useWebSocket.ts b/client-v3/src/composables/useWebSocket.ts index 28f3193a8..df1805da3 100644 --- a/client-v3/src/composables/useWebSocket.ts +++ b/client-v3/src/composables/useWebSocket.ts @@ -12,6 +12,8 @@ import type { WsMessage } from '@/types/api/websocket'; const INITIAL_RECONNECT_DELAY_MS = 1000; const MAX_RECONNECT_DELAY_MS = 30000; +/** RFC 6455 close code sent by the server when a message exceeds its size limit. */ +const WS_CLOSE_MESSAGE_TOO_BIG = 1009; let ws: WebSocket | null = null; let reconnectTimer: ReturnType | null = null; @@ -205,8 +207,18 @@ function connect(): void { } }; - ws.onclose = () => { + ws.onclose = (event?: CloseEvent) => { wsStore.$patch({ isConnected: false, authenticated: false }); + if (event?.code === WS_CLOSE_MESSAGE_TOO_BIG) { + // The server dropped us for sending an over-sized message. Back off (and tell the user) + // rather than reconnecting at the minimum delay, which would loop if the oversized + // message is re-sent on every connect. + errorCount++; + log.error('WebSocket closed by server: message exceeded the maximum size'); + if (errorCount === 1) { + toast.error('Server closed the connection: message too large'); + } + } log.info('WebSocket closed, scheduling reconnect'); scheduleReconnect(); }; diff --git a/docker-entrypoint.sh b/docker-entrypoint.sh new file mode 100755 index 000000000..b9f57fe7e --- /dev/null +++ b/docker-entrypoint.sh @@ -0,0 +1,27 @@ +#!/bin/sh +# Container entrypoint: fix ownership of the data directory left behind by +# older (root) images, then drop privileges and run the server. +set -eu + +APP_USER=digiscript +DATA_DIR=/server/conf + +if [ "$(id -u)" = "0" ]; then + # Cheap check first: only walk the tree if the top-level directory or one of + # the well-known files is not already owned by the app user. + app_uid="$(id -u "$APP_USER")" + needs_chown=0 + for path in "$DATA_DIR" "$DATA_DIR/digiscript.json" "$DATA_DIR/digiscript.sqlite"; do + if [ -e "$path" ] && [ "$(stat -c %u "$path")" != "$app_uid" ]; then + needs_chown=1 + fi + done + if [ "$needs_chown" = "1" ]; then + echo "Updating ownership of $DATA_DIR for user $APP_USER (one-time upgrade step)" + chown -R "$APP_USER:$APP_USER" "$DATA_DIR" + fi + exec gosu "$APP_USER" python3 main.py "$@" +fi + +# Started with --user (or rootless): nothing to chown, just run. +exec python3 main.py "$@" diff --git a/server/controllers/ws_controller.py b/server/controllers/ws_controller.py index 5953c27dc..249e4b5e3 100644 --- a/server/controllers/ws_controller.py +++ b/server/controllers/ws_controller.py @@ -33,6 +33,7 @@ from utils.web.base_controller import DatabaseMixin from utils.web.pending_disconnects import disconnect_key from utils.web.route import ApiRoute, ApiVersion +from utils.web.size_limits import LoggingWebSocketProtocol from utils.web.ws_session_lifecycle import ( assign_session_user, broadcast, @@ -145,6 +146,13 @@ def check_origin(self, origin): return True return super().check_origin(origin) + def get_websocket_protocol(self): + """Use a protocol that logs when a message exceeds the size limit.""" + protocol = super().get_websocket_protocol() + if protocol is not None: + protocol.__class__ = LoggingWebSocketProtocol + return protocol + @gen.coroutine def open(self, *args: str, **kwargs: str) -> Optional[Awaitable[None]]: self.__setattr__("internal_id", str(uuid4())) diff --git a/server/digi_server/app_server.py b/server/digi_server/app_server.py index fc98008a6..e98723d55 100644 --- a/server/digi_server/app_server.py +++ b/server/digi_server/app_server.py @@ -45,14 +45,10 @@ from utils.web.jwt_service import JWTService from utils.web.pending_disconnects import PendingDisconnects from utils.web.route import Route - - -# Largest HTTP request body accepted by the server (passed to ``listen`` in -# ``main.py``). Legitimate payloads are JSON well under this size. -MAX_BODY_SIZE = 10 * 1024 * 1024 -# Largest single WebSocket message accepted: bigger than any control message, -# with headroom for Yjs document syncs. -MAX_WEBSOCKET_MESSAGE_SIZE = 16 * 1024 * 1024 +from utils.web.size_limits import ( + DEFAULT_MAX_WS_MESSAGE_SIZE_MB, + MIB, +) class DigiScriptServer(PrometheusMixIn, Application): @@ -63,6 +59,7 @@ def __init__( settings_path=None, skip_migrations=False, skip_migrations_check=False, + max_ws_message_size_mb=DEFAULT_MAX_WS_MESSAGE_SIZE_MB, ): self._port: int = port self.digi_settings: Settings = Settings(self, settings_path) @@ -343,7 +340,7 @@ class AlembicVersion(self._db.Model): serve_traceback=False, db=self._db, websocket_ping_interval=5, - websocket_max_message_size=MAX_WEBSOCKET_MESSAGE_SIZE, + websocket_max_message_size=max_ws_message_size_mb * MIB, cookie_secret=self._get_cookie_secret(), login_url="/login", ) diff --git a/server/main.py b/server/main.py index 6eaef6b76..65eaa18a8 100755 --- a/server/main.py +++ b/server/main.py @@ -31,8 +31,14 @@ def ensure_writable_db_path(path): return path -from digi_server.app_server import MAX_BODY_SIZE, DigiScriptServer +from digi_server.app_server import DigiScriptServer from digi_server.logger import add_logging_level, get_logger +from utils.web.size_limits import ( + DEFAULT_MAX_BODY_SIZE_MB, + DEFAULT_MAX_WS_MESSAGE_SIZE_MB, + MIB, + install_body_limit_logging, +) add_logging_level("TRACE", logging.DEBUG - 5) @@ -45,6 +51,18 @@ def ensure_writable_db_path(path): help="Development mode: autoreload, relaxed WebSocket origin checks. " "Never enable on a deployed server.", ) +define( + "max_body_size_mb", + type=int, + default=DEFAULT_MAX_BODY_SIZE_MB, + help="Maximum HTTP request body size in MiB (restart required)", +) +define( + "max_ws_message_size_mb", + type=int, + default=DEFAULT_MAX_WS_MESSAGE_SIZE_MB, + help="Maximum single WebSocket message size in MiB (restart required)", +) define("port", type=int, default=8080, help="port to listen on") define("settings_path", type=str, default=None, help="Path to settings JSON file") define("skip_migrations", type=bool, default=False, help="skip database migrations") @@ -126,10 +144,13 @@ def patched_define( debug=options.debug, settings_path=options.settings_path, skip_migrations=options.skip_migrations, + max_ws_message_size_mb=options.max_ws_message_size_mb, ) await app.configure() - app.listen(options.port, max_body_size=MAX_BODY_SIZE) + max_body_size = options.max_body_size_mb * MIB + install_body_limit_logging(max_body_size) + app.listen(options.port, max_body_size=max_body_size) get_logger().info(f"Listening on port: {options.port}") if options.debug: get_logger().warning("Running in debug mode") diff --git a/server/test/controllers/test_ws_controller.py b/server/test/controllers/test_ws_controller.py index 08525d2fc..5b708d314 100644 --- a/server/test/controllers/test_ws_controller.py +++ b/server/test/controllers/test_ws_controller.py @@ -16,7 +16,7 @@ from sqlalchemy import select from tornado.httpclient import HTTPRequest from tornado.testing import gen_test -from tornado.websocket import websocket_connect +from tornado.websocket import WebSocketClosedError, websocket_connect from controllers.ws_controller import WebSocketController from digi_server.logger import get_logger @@ -36,6 +36,7 @@ disconnect_key, room_close_key, ) +from utils.web.size_limits import MIB from utils.web.ws_session_lifecycle import FINALISE_ATTEMPTS @@ -3666,6 +3667,28 @@ async def test_force_logout_of_leader_hands_leadership_on(self): ws_l.close() +class TestWSMessageSizeLimit(DigiScriptTestCase): + @gen_test + async def test_oversized_message_closes_connection_and_logs(self): + """A message above the cap closes the socket (1009) and is logged.""" + limit = MIB + self._app.settings["websocket_max_message_size"] = limit + conn = await websocket_connect( + f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" + ) + with self.assertLogs("DigiScript", level="WARNING") as logs: + try: + await conn.write_message("x" * (limit + 1024)) + except WebSocketClosedError: + pass + # Drain greeting messages; the server then closes the connection. + message = await conn.read_message() + while message is not None: + message = await conn.read_message() + self.assertTrue(any("exceeds the maximum" in m for m in logs.output)) + self.assertTrue(any(str(limit) in m for m in logs.output)) + + class TestWSHandlerMaps(DigiScriptTestCase): """Every op in the dispatch maps resolves to a handler method.""" diff --git a/server/test/digi_server/test_digi_server.py b/server/test/digi_server/test_digi_server.py index 0572580ce..76c1c8e58 100644 --- a/server/test/digi_server/test_digi_server.py +++ b/server/test/digi_server/test_digi_server.py @@ -1,3 +1,6 @@ +import ast +from pathlib import Path + import tornado.escape from sqlalchemy import func, select from tornado.testing import gen_test @@ -6,6 +9,11 @@ from models.settings import SystemSettings from models.user import User from test.conftest import DigiScriptTestCase +from utils.web.size_limits import ( + DEFAULT_MAX_BODY_SIZE_MB, + DEFAULT_MAX_WS_MESSAGE_SIZE_MB, + MIB, +) class TestDigiScriptServer(DigiScriptTestCase): @@ -17,6 +25,44 @@ def test_debug(self): self.assertTrue("status" in response_body) self.assertEqual("OK", response_body["status"]) + def test_debug_mode_is_opt_in(self): + """Debug mode must be opt-in via ``--debug``.""" + tree = ast.parse( + (Path(__file__).parents[2] / "main.py").read_text(encoding="utf-8") + ) + defaults = [ + kw.value.value + for node in ast.walk(tree) + if isinstance(node, ast.Call) + and getattr(node.func, "id", None) == "define" + and node.args + and getattr(node.args[0], "value", None) == "debug" + for kw in node.keywords + if kw.arg == "default" + ] + self.assertEqual([False], defaults) + + def test_traceback_not_returned_to_client(self): + """Even with debug=True (as in the test app) no traceback is returned.""" + self.assertTrue(self._app.settings["debug"]) + self.assertFalse(self._app.settings["serve_traceback"]) + response = self.fetch( + "/api/v1/auth/login", + method="POST", + body="{not valid json", + ) + self.assertGreaterEqual(response.code, 400) + self.assertNotIn(b"Traceback", response.body) + self.assertNotIn(b".py", response.body) + + def test_default_size_limits(self): + """Defaults leave >5x headroom over the measured legitimate payloads.""" + self.assertEqual(5, DEFAULT_MAX_BODY_SIZE_MB) + self.assertEqual( + DEFAULT_MAX_WS_MESSAGE_SIZE_MB * MIB, + self._app.settings["websocket_max_message_size"], + ) + def test_api_debug(self): response = self.fetch("/api/v1/debug") response_body = tornado.escape.json_decode(response.body) diff --git a/server/test/digi_server/test_server_hardening.py b/server/test/digi_server/test_server_hardening.py deleted file mode 100644 index 3e61eac83..000000000 --- a/server/test/digi_server/test_server_hardening.py +++ /dev/null @@ -1,83 +0,0 @@ -import ast -from pathlib import Path - -from tornado.httpclient import HTTPRequest -from tornado.httpserver import HTTPServer -from tornado.testing import bind_unused_port, gen_test -from tornado.websocket import WebSocketClosedError, websocket_connect - -from digi_server.app_server import MAX_BODY_SIZE, MAX_WEBSOCKET_MESSAGE_SIZE -from test.conftest import DigiScriptTestCase - - -class TestServerHardening(DigiScriptTestCase): - def test_debug_option_defaults_to_off(self): - """Debug mode must be opt-in via ``--debug``.""" - tree = ast.parse( - (Path(__file__).parents[2] / "main.py").read_text(encoding="utf-8") - ) - defaults = [ - kw.value.value - for node in ast.walk(tree) - if isinstance(node, ast.Call) - and getattr(node.func, "id", None) == "define" - and node.args - and getattr(node.args[0], "value", None) == "debug" - for kw in node.keywords - if kw.arg == "default" - ] - self.assertEqual([False], defaults) - - def test_tracebacks_not_served_in_debug_mode(self): - """Even with debug=True (as in the test app) no traceback is returned.""" - self.assertTrue(self._app.settings["debug"]) - self.assertFalse(self._app.settings["serve_traceback"]) - response = self.fetch( - "/api/v1/auth/login", - method="POST", - body="{not valid json", - ) - self.assertGreaterEqual(response.code, 400) - self.assertNotIn(b"Traceback", response.body) - self.assertNotIn(b".py", response.body) - - @gen_test - async def test_oversized_http_body_rejected(self): - """The production HTTP server refuses bodies above ``MAX_BODY_SIZE``.""" - sock, port = bind_unused_port() - server = HTTPServer(self._app, max_body_size=MAX_BODY_SIZE) - server.add_sockets([sock]) - try: - request = HTTPRequest( - f"http://127.0.0.1:{port}/api/v1/auth/login", - method="POST", - body="x" * (MAX_BODY_SIZE + 1024), - ) - # The server rejects the request while it is still being sent, so - # the client sees either an error response or a dropped connection. - try: - response = await self.http_client.fetch(request, raise_error=False) - self.assertGreaterEqual(response.code, 400) - except OSError: - pass - finally: - server.stop() - sock.close() - - @gen_test - async def test_oversized_websocket_message_closes_connection(self): - """A WebSocket message above the configured cap terminates the socket.""" - limit = self._app.settings["websocket_max_message_size"] - self.assertEqual(MAX_WEBSOCKET_MESSAGE_SIZE, limit) - conn = await websocket_connect( - f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" - ) - try: - await conn.write_message("x" * (limit + 1024)) - except WebSocketClosedError: - pass - # Drain any greeting messages; the server then closes the connection. - message = await conn.read_message() - while message is not None: - message = await conn.read_message() - self.assertIsNone(message) diff --git a/server/test/utils/web/test_size_limits.py b/server/test/utils/web/test_size_limits.py new file mode 100644 index 000000000..97efbb2b0 --- /dev/null +++ b/server/test/utils/web/test_size_limits.py @@ -0,0 +1,43 @@ +import logging + +from tornado import gen +from tornado.httpclient import HTTPRequest +from tornado.httpserver import HTTPServer +from tornado.testing import bind_unused_port, gen_test + +from test.conftest import DigiScriptTestCase +from utils.web.size_limits import MIB, install_body_limit_logging + + +class TestBodyLimitLogging(DigiScriptTestCase): + @gen_test + async def test_oversized_body_rejected_and_logged(self): + """Bodies above the limit are refused and a warning names the limit.""" + limit = MIB + log_filter = install_body_limit_logging(limit) + sock, port = bind_unused_port() + server = HTTPServer(self._app, max_body_size=limit) + server.add_sockets([sock]) + try: + request = HTTPRequest( + f"http://127.0.0.1:{port}/api/v1/auth/login", + method="POST", + body="x" * (limit + 1024), + ) + with self.assertLogs("tornado.general", level="INFO") as logs: + # The server rejects the request while it is still being sent, + # so the client sees an error response or a dropped connection. + try: + response = await self.http_client.fetch(request, raise_error=False) + self.assertGreaterEqual(response.code, 400) + except OSError: + pass + await gen.sleep(0.1) + warnings = [r for r in logs.records if r.levelname == "WARNING"] + self.assertEqual(1, len(warnings)) + self.assertIn(str(limit), warnings[0].getMessage()) + self.assertIn("127.0.0.1", warnings[0].getMessage()) + finally: + logging.getLogger("tornado.general").removeFilter(log_filter) + server.stop() + sock.close() diff --git a/server/utils/web/size_limits.py b/server/utils/web/size_limits.py new file mode 100644 index 000000000..47db8d2cf --- /dev/null +++ b/server/utils/web/size_limits.py @@ -0,0 +1,75 @@ +"""Request size limits and the logging that makes hitting them observable. + +Tornado enforces both limits itself and drops the offending request or +connection quietly (the HTTP rejection is logged at INFO on +``tornado.general`` and the WebSocket close is not logged at all). This module +adds a clear WARNING naming the limit and the client address. + +The defaults were chosen from measurements of a 450 page / 18,000 line script: +the largest REST body is one page of lines (~17 KiB), the largest legitimate +WebSocket frame is a base64 Yjs update (a whole-script insert is ~14 MiB, an +edit touching every line is under 1 MiB). +""" + +from __future__ import annotations + +import logging + +from tornado.websocket import WebSocketProtocol13 + +from digi_server.logger import get_logger + + +MIB = 1024 * 1024 + +#: Default maximum HTTP request body, in MiB (``--max_body_size_mb``). +DEFAULT_MAX_BODY_SIZE_MB = 5 +#: Default maximum single WebSocket message, in MiB (``--max_ws_message_size_mb``). +DEFAULT_MAX_WS_MESSAGE_SIZE_MB = 64 + +WS_CLOSE_MESSAGE_TOO_BIG = 1009 + + +class _BodyTooLargeFilter(logging.Filter): + """Rewrites Tornado's INFO "Content-Length too long" record as a WARNING.""" + + def __init__(self, max_body_size: int): + super().__init__() + self._max_body_size = max_body_size + + def filter(self, record: logging.LogRecord) -> bool: + if "Content-Length too long" in record.getMessage(): + client = record.args[0] if record.args else "unknown client" + record.levelno = logging.WARNING + record.levelname = "WARNING" + record.msg = ( + "Rejected HTTP request from %s: body exceeds the maximum of %d " + "bytes (--max_body_size_mb)" + ) + record.args = (client, self._max_body_size) + return True + + +def install_body_limit_logging(max_body_size: int) -> logging.Filter: + """Log a warning when an HTTP request is rejected for its body size. + + :param max_body_size: The configured limit in bytes (used in the message). + :returns: The installed filter (so callers/tests can remove it). + """ + log_filter = _BodyTooLargeFilter(max_body_size) + logging.getLogger("tornado.general").addFilter(log_filter) + return log_filter + + +class LoggingWebSocketProtocol(WebSocketProtocol13): + """WebSocket protocol that logs when it closes a socket for size (1009).""" + + def close(self, code=None, reason=None): + if code == WS_CLOSE_MESSAGE_TOO_BIG: + handler = self.handler + limit = getattr(self.params, "max_message_size", None) + get_logger().warning( + f"Closing WebSocket from {handler.request.remote_ip}: message " + f"exceeds the maximum of {limit} bytes (--max_ws_message_size_mb)" + ) + super().close(code, reason) From 3dce9d07cddebf082d73f357107be4a648cb104f Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Tue, 20 Oct 2026 12:30:30 +0100 Subject: [PATCH 3/6] Drop Docker and size-limit changes; add request size histograms Co-Authored-By: Claude Sonnet 5.5 --- Dockerfile | 16 ++-- README.md | 39 ++++------ docker-entrypoint.sh | 27 ------- server/controllers/ws_controller.py | 11 +-- server/digi_server/app_server.py | 9 +-- server/main.py | 23 +----- server/test/controllers/test_ws_controller.py | 42 ++++++----- server/test/digi_server/test_digi_server.py | 37 ++++++--- server/test/utils/web/test_size_limits.py | 43 ----------- server/utils/web/request_size_metrics.py | 65 ++++++++++++++++ server/utils/web/size_limits.py | 75 ------------------- 11 files changed, 141 insertions(+), 246 deletions(-) delete mode 100755 docker-entrypoint.sh delete mode 100644 server/test/utils/web/test_size_limits.py create mode 100644 server/utils/web/request_size_metrics.py delete mode 100644 server/utils/web/size_limits.py diff --git a/Dockerfile b/Dockerfile index 72d701231..5d693dce2 100644 --- a/Dockerfile +++ b/Dockerfile @@ -27,22 +27,16 @@ RUN pnpm run build FROM python:3.13-bookworm -RUN apt-get update \ - && apt-get install -y --no-install-recommends gosu \ - && rm -rf /var/lib/apt/lists/* - COPY /server/requirements.txt ./requirements.txt RUN pip install -r requirements.txt +RUN apt update +RUN apt install -y nano + COPY /server /server COPY --from=build_v2 /server/static /server/static COPY --from=build_v3 /server/static /server/static WORKDIR /server -RUN useradd --system --create-home --uid 1000 digiscript \ - && mkdir -p conf \ - && chown -R digiscript:digiscript /server/conf -COPY docker-entrypoint.sh /usr/local/bin/docker-entrypoint.sh +RUN mkdir conf EXPOSE 8080 -# Starts as root only to fix ownership of existing volumes, then drops to the -# digiscript user (see docker-entrypoint.sh). -ENTRYPOINT ["docker-entrypoint.sh"] +ENTRYPOINT ["python3", "main.py"] diff --git a/README.md b/README.md index 22c0d149b..8690211d4 100644 --- a/README.md +++ b/README.md @@ -86,29 +86,22 @@ docker-compose up -d DigiScript will be available at `http://localhost:8080` -**Upgrading from an older image:** the container now runs the server as an unprivileged `digiscript` -user. No manual steps are needed: on start, the entrypoint (`docker-entrypoint.sh`) runs as root, -fixes the ownership of an existing `/server/conf` volume or bind mount if it is still root-owned -(a one-time `chown`, skipped when ownership is already correct), then drops privileges. If you start -the container with `--user`/`user:` the entrypoint skips the ownership fix, so the mounted directory -must already be writable by that user. - -### Server options - -Pass these to `python3 main.py` (or append them to the container command / compose `command:`): - -| Option | Default | Purpose | -|--------|---------|---------| -| `--debug` | off | Development only: autoreload and relaxed WebSocket origin checks | -| `--max_body_size_mb` | 5 | Largest accepted HTTP request body, in MiB | -| `--max_ws_message_size_mb` | 64 | Largest accepted single WebSocket message, in MiB | - -The defaults were derived from a 450 page / 18,000 line script: the largest normal REST request is -one page of lines (about 17 KiB), and the largest WebSocket frame is a base64-encoded collaborative -editing update (a rewrite touching every line is under 1 MiB; inserting an entire 450 page script in -one go is about 14 MiB). A request over the HTTP limit is refused and an over-sized WebSocket message -closes the connection (close code 1009); both log a warning naming the limit and the client address. -Raise the limits and restart the server if you legitimately hit them. +### Request size metrics + +The server exposes two Prometheus histograms at `/debug/metrics` so that request size limits can be +tuned from real usage (Tornado's defaults currently apply: 100 MB HTTP bodies, 10 MiB WebSocket messages): + +| Metric | Labels | Meaning | +|--------|--------|---------| +| `digiscript_http_request_body_bytes` | `handler`, `method` | Size of HTTP request bodies (requests with a body only) | +| `digiscript_ws_message_bytes` | none | Size of inbound WebSocket messages | + +Buckets are powers of 4 from 1 KiB to 256 MiB. For example, the 99th percentile WebSocket message size +over the last day in Prometheus: + +``` +histogram_quantile(0.99, sum(rate(digiscript_ws_message_bytes_bucket[1d])) by (le)) +``` ### Manual Installation diff --git a/docker-entrypoint.sh b/docker-entrypoint.sh deleted file mode 100755 index b9f57fe7e..000000000 --- a/docker-entrypoint.sh +++ /dev/null @@ -1,27 +0,0 @@ -#!/bin/sh -# Container entrypoint: fix ownership of the data directory left behind by -# older (root) images, then drop privileges and run the server. -set -eu - -APP_USER=digiscript -DATA_DIR=/server/conf - -if [ "$(id -u)" = "0" ]; then - # Cheap check first: only walk the tree if the top-level directory or one of - # the well-known files is not already owned by the app user. - app_uid="$(id -u "$APP_USER")" - needs_chown=0 - for path in "$DATA_DIR" "$DATA_DIR/digiscript.json" "$DATA_DIR/digiscript.sqlite"; do - if [ -e "$path" ] && [ "$(stat -c %u "$path")" != "$app_uid" ]; then - needs_chown=1 - fi - done - if [ "$needs_chown" = "1" ]; then - echo "Updating ownership of $DATA_DIR for user $APP_USER (one-time upgrade step)" - chown -R "$APP_USER:$APP_USER" "$DATA_DIR" - fi - exec gosu "$APP_USER" python3 main.py "$@" -fi - -# Started with --user (or rootless): nothing to chown, just run. -exec python3 main.py "$@" diff --git a/server/controllers/ws_controller.py b/server/controllers/ws_controller.py index 249e4b5e3..295dcb5f6 100644 --- a/server/controllers/ws_controller.py +++ b/server/controllers/ws_controller.py @@ -32,8 +32,8 @@ from rbac.role import Role from utils.web.base_controller import DatabaseMixin from utils.web.pending_disconnects import disconnect_key +from utils.web.request_size_metrics import WSMessageSizeMetricsMixin from utils.web.route import ApiRoute, ApiVersion -from utils.web.size_limits import LoggingWebSocketProtocol from utils.web.ws_session_lifecycle import ( assign_session_user, broadcast, @@ -64,7 +64,7 @@ @ApiRoute("ws", ApiVersion.V1) -class WebSocketController(DatabaseMixin, WebSocketHandler): +class WebSocketController(WSMessageSizeMetricsMixin, DatabaseMixin, WebSocketHandler): # Live-show ops only the leader may send, and the method that handles each. _LEADER_OP_HANDLERS = { "SCRIPT_SCROLL": "_op_script_scroll", @@ -146,13 +146,6 @@ def check_origin(self, origin): return True return super().check_origin(origin) - def get_websocket_protocol(self): - """Use a protocol that logs when a message exceeds the size limit.""" - protocol = super().get_websocket_protocol() - if protocol is not None: - protocol.__class__ = LoggingWebSocketProtocol - return protocol - @gen.coroutine def open(self, *args: str, **kwargs: str) -> Optional[Awaitable[None]]: self.__setattr__("internal_id", str(uuid4())) diff --git a/server/digi_server/app_server.py b/server/digi_server/app_server.py index e98723d55..6eefcd6ba 100644 --- a/server/digi_server/app_server.py +++ b/server/digi_server/app_server.py @@ -44,11 +44,8 @@ from utils.version_checker import VersionChecker from utils.web.jwt_service import JWTService from utils.web.pending_disconnects import PendingDisconnects +from utils.web.request_size_metrics import observe_http_request from utils.web.route import Route -from utils.web.size_limits import ( - DEFAULT_MAX_WS_MESSAGE_SIZE_MB, - MIB, -) class DigiScriptServer(PrometheusMixIn, Application): @@ -59,7 +56,6 @@ def __init__( settings_path=None, skip_migrations=False, skip_migrations_check=False, - max_ws_message_size_mb=DEFAULT_MAX_WS_MESSAGE_SIZE_MB, ): self._port: int = port self.digi_settings: Settings = Settings(self, settings_path) @@ -340,7 +336,6 @@ class AlembicVersion(self._db.Model): serve_traceback=False, db=self._db, websocket_ping_interval=5, - websocket_max_message_size=max_ws_message_size_mb * MIB, cookie_secret=self._get_cookie_secret(), login_url="/login", ) @@ -348,6 +343,8 @@ class AlembicVersion(self._db.Model): def log_request(self, handler): from tornado.log import access_log # noqa: PLC0415 + observe_http_request(handler) + if handler.request.path in Route.ignored_logging_routes(): return diff --git a/server/main.py b/server/main.py index 65eaa18a8..ccbf5b02a 100755 --- a/server/main.py +++ b/server/main.py @@ -33,12 +33,6 @@ def ensure_writable_db_path(path): from digi_server.app_server import DigiScriptServer from digi_server.logger import add_logging_level, get_logger -from utils.web.size_limits import ( - DEFAULT_MAX_BODY_SIZE_MB, - DEFAULT_MAX_WS_MESSAGE_SIZE_MB, - MIB, - install_body_limit_logging, -) add_logging_level("TRACE", logging.DEBUG - 5) @@ -51,18 +45,6 @@ def ensure_writable_db_path(path): help="Development mode: autoreload, relaxed WebSocket origin checks. " "Never enable on a deployed server.", ) -define( - "max_body_size_mb", - type=int, - default=DEFAULT_MAX_BODY_SIZE_MB, - help="Maximum HTTP request body size in MiB (restart required)", -) -define( - "max_ws_message_size_mb", - type=int, - default=DEFAULT_MAX_WS_MESSAGE_SIZE_MB, - help="Maximum single WebSocket message size in MiB (restart required)", -) define("port", type=int, default=8080, help="port to listen on") define("settings_path", type=str, default=None, help="Path to settings JSON file") define("skip_migrations", type=bool, default=False, help="skip database migrations") @@ -144,13 +126,10 @@ def patched_define( debug=options.debug, settings_path=options.settings_path, skip_migrations=options.skip_migrations, - max_ws_message_size_mb=options.max_ws_message_size_mb, ) await app.configure() - max_body_size = options.max_body_size_mb * MIB - install_body_limit_logging(max_body_size) - app.listen(options.port, max_body_size=max_body_size) + app.listen(options.port) get_logger().info(f"Listening on port: {options.port}") if options.debug: get_logger().warning("Running in debug mode") diff --git a/server/test/controllers/test_ws_controller.py b/server/test/controllers/test_ws_controller.py index 5b708d314..dd575bdb6 100644 --- a/server/test/controllers/test_ws_controller.py +++ b/server/test/controllers/test_ws_controller.py @@ -16,7 +16,7 @@ from sqlalchemy import select from tornado.httpclient import HTTPRequest from tornado.testing import gen_test -from tornado.websocket import WebSocketClosedError, websocket_connect +from tornado.websocket import websocket_connect from controllers.ws_controller import WebSocketController from digi_server.logger import get_logger @@ -36,7 +36,7 @@ disconnect_key, room_close_key, ) -from utils.web.size_limits import MIB +from utils.web.request_size_metrics import ws_message_bytes from utils.web.ws_session_lifecycle import FINALISE_ATTEMPTS @@ -3667,26 +3667,32 @@ async def test_force_logout_of_leader_hands_leadership_on(self): ws_l.close() -class TestWSMessageSizeLimit(DigiScriptTestCase): +class TestWSMessageSizeMetrics(DigiScriptTestCase): + @staticmethod + def _message_count(): + return next( + sample.value + for metric in ws_message_bytes.collect() + for sample in metric.samples + if sample.name.endswith("_count") + ) + @gen_test - async def test_oversized_message_closes_connection_and_logs(self): - """A message above the cap closes the socket (1009) and is logged.""" - limit = MIB - self._app.settings["websocket_max_message_size"] = limit + async def test_inbound_message_size_observed(self): + """Every inbound WebSocket message is recorded in the size histogram.""" + before = self._message_count() conn = await websocket_connect( f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" ) - with self.assertLogs("DigiScript", level="WARNING") as logs: - try: - await conn.write_message("x" * (limit + 1024)) - except WebSocketClosedError: - pass - # Drain greeting messages; the server then closes the connection. - message = await conn.read_message() - while message is not None: - message = await conn.read_message() - self.assertTrue(any("exceeds the maximum" in m for m in logs.output)) - self.assertTrue(any(str(limit) in m for m in logs.output)) + await conn.read_message() # SET_UUID greeting + await conn.write_message(json.dumps({"OP": "PING", "DATA": "x" * 100})) + await conn.write_message("not json") + for _ in range(50): + if self._message_count() >= before + 2: + break + await asyncio.sleep(0.05) + conn.close() + self.assertGreaterEqual(self._message_count(), before + 2) class TestWSHandlerMaps(DigiScriptTestCase): diff --git a/server/test/digi_server/test_digi_server.py b/server/test/digi_server/test_digi_server.py index 76c1c8e58..9b80a3f7b 100644 --- a/server/test/digi_server/test_digi_server.py +++ b/server/test/digi_server/test_digi_server.py @@ -9,11 +9,7 @@ from models.settings import SystemSettings from models.user import User from test.conftest import DigiScriptTestCase -from utils.web.size_limits import ( - DEFAULT_MAX_BODY_SIZE_MB, - DEFAULT_MAX_WS_MESSAGE_SIZE_MB, - MIB, -) +from utils.web.request_size_metrics import http_request_body_bytes class TestDigiScriptServer(DigiScriptTestCase): @@ -55,13 +51,30 @@ def test_traceback_not_returned_to_client(self): self.assertNotIn(b"Traceback", response.body) self.assertNotIn(b".py", response.body) - def test_default_size_limits(self): - """Defaults leave >5x headroom over the measured legitimate payloads.""" - self.assertEqual(5, DEFAULT_MAX_BODY_SIZE_MB) - self.assertEqual( - DEFAULT_MAX_WS_MESSAGE_SIZE_MB * MIB, - self._app.settings["websocket_max_message_size"], - ) + def test_request_body_size_observed(self): + """Request bodies are recorded in the size histogram, labelled by handler.""" + labels = ("ApiFallback", "POST") + before = self._body_count(*labels) + self.fetch("/api/v1/nonexistent", method="POST", body="x" * 2000) + self.assertEqual(before + 1, self._body_count(*labels)) + + def test_request_without_body_not_observed(self): + """Body-less requests do not add to the size histogram.""" + before = self._body_count("ApiFallback", "GET") + self.fetch("/api/v1/nonexistent") + self.assertEqual(before, self._body_count("ApiFallback", "GET")) + + @staticmethod + def _body_count(handler, method): + for metric in http_request_body_bytes.collect(): + for sample in metric.samples: + if ( + sample.name.endswith("_count") + and sample.labels.get("handler") == handler + and sample.labels.get("method") == method + ): + return sample.value + return 0 def test_api_debug(self): response = self.fetch("/api/v1/debug") diff --git a/server/test/utils/web/test_size_limits.py b/server/test/utils/web/test_size_limits.py deleted file mode 100644 index 97efbb2b0..000000000 --- a/server/test/utils/web/test_size_limits.py +++ /dev/null @@ -1,43 +0,0 @@ -import logging - -from tornado import gen -from tornado.httpclient import HTTPRequest -from tornado.httpserver import HTTPServer -from tornado.testing import bind_unused_port, gen_test - -from test.conftest import DigiScriptTestCase -from utils.web.size_limits import MIB, install_body_limit_logging - - -class TestBodyLimitLogging(DigiScriptTestCase): - @gen_test - async def test_oversized_body_rejected_and_logged(self): - """Bodies above the limit are refused and a warning names the limit.""" - limit = MIB - log_filter = install_body_limit_logging(limit) - sock, port = bind_unused_port() - server = HTTPServer(self._app, max_body_size=limit) - server.add_sockets([sock]) - try: - request = HTTPRequest( - f"http://127.0.0.1:{port}/api/v1/auth/login", - method="POST", - body="x" * (limit + 1024), - ) - with self.assertLogs("tornado.general", level="INFO") as logs: - # The server rejects the request while it is still being sent, - # so the client sees an error response or a dropped connection. - try: - response = await self.http_client.fetch(request, raise_error=False) - self.assertGreaterEqual(response.code, 400) - except OSError: - pass - await gen.sleep(0.1) - warnings = [r for r in logs.records if r.levelname == "WARNING"] - self.assertEqual(1, len(warnings)) - self.assertIn(str(limit), warnings[0].getMessage()) - self.assertIn("127.0.0.1", warnings[0].getMessage()) - finally: - logging.getLogger("tornado.general").removeFilter(log_filter) - server.stop() - sock.close() diff --git a/server/utils/web/request_size_metrics.py b/server/utils/web/request_size_metrics.py new file mode 100644 index 000000000..56f039b9a --- /dev/null +++ b/server/utils/web/request_size_metrics.py @@ -0,0 +1,65 @@ +"""Prometheus histograms of inbound HTTP body and WebSocket message sizes. + +The histograms are module-level so they are registered exactly once per +process, however many application instances are created (tests create many). +They are exposed alongside the other metrics at ``/debug/metrics`` and exist so +that request size limits can be tuned from real data. +""" + +from __future__ import annotations + +import functools + +from prometheus_client import Histogram + + +# Powers of 4 from 1 KiB to 256 MiB. +SIZE_BUCKETS = tuple(1024 * 4**i for i in range(10)) + +http_request_body_bytes = Histogram( + name="digiscript_http_request_body_bytes", + documentation="Size of HTTP request bodies in bytes (requests with a body only)", + buckets=SIZE_BUCKETS, + labelnames=("handler", "method"), +) + +ws_message_bytes = Histogram( + name="digiscript_ws_message_bytes", + documentation="Size of inbound WebSocket messages in bytes", + buckets=SIZE_BUCKETS, +) + + +def observe_http_request(handler) -> None: + """Record the body size of a finished HTTP request, if it had a body. + + The label is the handler class name (bounded), never the raw path. + + :param handler: The finished Tornado ``RequestHandler``. + """ + size = len(handler.request.body or b"") + if size: + http_request_body_bytes.labels( + type(handler).__name__, handler.request.method + ).observe(size) + + +class WSMessageSizeMetricsMixin: + """Observes the size of every message passed to a subclass's ``on_message``. + + ``on_message`` is wrapped when the subclass is created, so the subclass's + own method body needs no changes. + """ + + def __init_subclass__(cls, **kwargs): + super().__init_subclass__(**kwargs) + original = cls.__dict__.get("on_message") + if original is None: + return + + @functools.wraps(original) + async def on_message(self, message): + ws_message_bytes.observe(len(message)) + return await original(self, message) + + cls.on_message = on_message diff --git a/server/utils/web/size_limits.py b/server/utils/web/size_limits.py deleted file mode 100644 index 47db8d2cf..000000000 --- a/server/utils/web/size_limits.py +++ /dev/null @@ -1,75 +0,0 @@ -"""Request size limits and the logging that makes hitting them observable. - -Tornado enforces both limits itself and drops the offending request or -connection quietly (the HTTP rejection is logged at INFO on -``tornado.general`` and the WebSocket close is not logged at all). This module -adds a clear WARNING naming the limit and the client address. - -The defaults were chosen from measurements of a 450 page / 18,000 line script: -the largest REST body is one page of lines (~17 KiB), the largest legitimate -WebSocket frame is a base64 Yjs update (a whole-script insert is ~14 MiB, an -edit touching every line is under 1 MiB). -""" - -from __future__ import annotations - -import logging - -from tornado.websocket import WebSocketProtocol13 - -from digi_server.logger import get_logger - - -MIB = 1024 * 1024 - -#: Default maximum HTTP request body, in MiB (``--max_body_size_mb``). -DEFAULT_MAX_BODY_SIZE_MB = 5 -#: Default maximum single WebSocket message, in MiB (``--max_ws_message_size_mb``). -DEFAULT_MAX_WS_MESSAGE_SIZE_MB = 64 - -WS_CLOSE_MESSAGE_TOO_BIG = 1009 - - -class _BodyTooLargeFilter(logging.Filter): - """Rewrites Tornado's INFO "Content-Length too long" record as a WARNING.""" - - def __init__(self, max_body_size: int): - super().__init__() - self._max_body_size = max_body_size - - def filter(self, record: logging.LogRecord) -> bool: - if "Content-Length too long" in record.getMessage(): - client = record.args[0] if record.args else "unknown client" - record.levelno = logging.WARNING - record.levelname = "WARNING" - record.msg = ( - "Rejected HTTP request from %s: body exceeds the maximum of %d " - "bytes (--max_body_size_mb)" - ) - record.args = (client, self._max_body_size) - return True - - -def install_body_limit_logging(max_body_size: int) -> logging.Filter: - """Log a warning when an HTTP request is rejected for its body size. - - :param max_body_size: The configured limit in bytes (used in the message). - :returns: The installed filter (so callers/tests can remove it). - """ - log_filter = _BodyTooLargeFilter(max_body_size) - logging.getLogger("tornado.general").addFilter(log_filter) - return log_filter - - -class LoggingWebSocketProtocol(WebSocketProtocol13): - """WebSocket protocol that logs when it closes a socket for size (1009).""" - - def close(self, code=None, reason=None): - if code == WS_CLOSE_MESSAGE_TOO_BIG: - handler = self.handler - limit = getattr(self.params, "max_message_size", None) - get_logger().warning( - f"Closing WebSocket from {handler.request.remote_ip}: message " - f"exceeds the maximum of {limit} bytes (--max_ws_message_size_mb)" - ) - super().close(code, reason) From 19c012c70aa4d4f50528d24bb220dc62127d7d42 Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Tue, 20 Oct 2026 12:54:29 +0100 Subject: [PATCH 4/6] Address review: persistent 1009 backoff, bounded method label, hardened WS size mixin, test tightening Co-Authored-By: Claude Sonnet 5.5 --- .../useWebSocket.closeTooBig.test.ts | 50 +++++++++++++++++-- client-v3/src/composables/useWebSocket.ts | 36 ++++++++++--- .../controllers/api/v1/show/test_shows.py | 9 +++- server/test/controllers/test_ws_controller.py | 27 +++++++++- server/test/digi_server/test_digi_server.py | 22 +++++++- server/utils/web/request_size_metrics.py | 43 +++++++++++++--- 6 files changed, 165 insertions(+), 22 deletions(-) diff --git a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts index d2abd06bf..aa97196f2 100644 --- a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts +++ b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts @@ -1,7 +1,4 @@ import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest'; -import { createPinia, setActivePinia } from 'pinia'; -import { useWebSocket } from './useWebSocket'; -import { toast } from '@/js/toast'; // Close code 1009 (message too big) must back off instead of reconnecting at the minimum // delay forever. @@ -28,12 +25,20 @@ class FakeWebSocket { send(): void {} } +// The composable keeps its backoff state at module level, so load a fresh copy per test. +let useWebSocket: typeof import('./useWebSocket').useWebSocket; +let toast: typeof import('@/js/toast').toast; + describe('close code 1009', () => { - beforeEach(() => { + beforeEach(async () => { + vi.resetModules(); FakeWebSocket.instances = []; vi.useFakeTimers(); vi.stubGlobal('WebSocket', FakeWebSocket); + const { createPinia, setActivePinia } = await import('pinia'); setActivePinia(createPinia()); + ({ useWebSocket } = await import('./useWebSocket')); + ({ toast } = await import('@/js/toast')); }); afterEach(() => { @@ -41,6 +46,43 @@ describe('close code 1009', () => { vi.unstubAllGlobals(); }); + it('keeps backing off when authentication succeeds between closes', async () => { + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + vi.advanceTimersByTime(2100); + expect(FakeWebSocket.instances).toHaveLength(2); + + // Reconnect and re-authenticate (this resets the generic error counter). + FakeWebSocket.instances[1].onmessage?.({ data: JSON.stringify({ OP: 'WS_AUTH_SUCCESS' }) }); + await vi.advanceTimersByTimeAsync(0); + FakeWebSocket.instances[1].onclose?.({ code: 1009 }); + + // Delay must have doubled to 4s rather than starting over at 2s. + vi.advanceTimersByTime(3500); + expect(FakeWebSocket.instances).toHaveLength(2); + vi.advanceTimersByTime(600); + expect(FakeWebSocket.instances).toHaveLength(3); + expect(toast.error).toHaveBeenCalledTimes(1); + }); + + it('reconnects even if showing the toast throws', () => { + vi.mocked(toast.error).mockImplementationOnce(() => { + throw new Error('toast failed'); + }); + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + vi.advanceTimersByTime(2100); + expect(FakeWebSocket.instances).toHaveLength(2); + }); + + it('does not back off or notify on a normal close', () => { + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1000 }); + expect(toast.error).not.toHaveBeenCalled(); + vi.advanceTimersByTime(1100); + expect(FakeWebSocket.instances).toHaveLength(2); + }); + it('notifies the user once and backs off between reconnects', () => { useWebSocket().connect(); FakeWebSocket.instances[0].onclose?.({ code: 1009 }); diff --git a/client-v3/src/composables/useWebSocket.ts b/client-v3/src/composables/useWebSocket.ts index df1805da3..8ca6756eb 100644 --- a/client-v3/src/composables/useWebSocket.ts +++ b/client-v3/src/composables/useWebSocket.ts @@ -14,13 +14,22 @@ const INITIAL_RECONNECT_DELAY_MS = 1000; const MAX_RECONNECT_DELAY_MS = 30000; /** RFC 6455 close code sent by the server when a message exceeds its size limit. */ const WS_CLOSE_MESSAGE_TOO_BIG = 1009; +const STABLE_CONNECTION_MS = 30000; let ws: WebSocket | null = null; let reconnectTimer: ReturnType | null = null; let errorCount = 0; +// Consecutive 1009 closes. Kept apart from errorCount, which a successful authentication resets, +// so a client that keeps tripping the limit still backs off. Cleared once a connection has stayed +// up for STABLE_CONNECTION_MS. +let tooBigCount = 0; +let stableTimer: ReturnType | null = null; function getReconnectDelay(): number { - return Math.min(INITIAL_RECONNECT_DELAY_MS * 2 ** errorCount, MAX_RECONNECT_DELAY_MS); + return Math.min( + INITIAL_RECONNECT_DELAY_MS * 2 ** Math.max(errorCount, tooBigCount), + MAX_RECONNECT_DELAY_MS + ); } /** Returns false (after logging) if the socket isn't open, so callers can react to a dropped frame. */ @@ -187,6 +196,11 @@ function connect(): void { ); } log.info('WebSocket connected'); + if (stableTimer) clearTimeout(stableTimer); + stableTimer = setTimeout(() => { + stableTimer = null; + tooBigCount = 0; + }, STABLE_CONNECTION_MS); if (wasErrored) { const showStore = useShowStore(); if (showStore.currentSession != null) { @@ -209,18 +223,28 @@ function connect(): void { ws.onclose = (event?: CloseEvent) => { wsStore.$patch({ isConnected: false, authenticated: false }); - if (event?.code === WS_CLOSE_MESSAGE_TOO_BIG) { + if (stableTimer) { + clearTimeout(stableTimer); + stableTimer = null; + } + const tooBig = event?.code === WS_CLOSE_MESSAGE_TOO_BIG; + if (tooBig) { // The server dropped us for sending an over-sized message. Back off (and tell the user) // rather than reconnecting at the minimum delay, which would loop if the oversized // message is re-sent on every connect. - errorCount++; + tooBigCount++; log.error('WebSocket closed by server: message exceeded the maximum size'); - if (errorCount === 1) { - toast.error('Server closed the connection: message too large'); - } } log.info('WebSocket closed, scheduling reconnect'); + // Schedule before notifying so a failing toast can never stop the reconnect. scheduleReconnect(); + if (tooBig && tooBigCount === 1) { + try { + toast.error('Server closed the connection: message too large'); + } catch (e) { + log.error('Failed to show WebSocket close toast:', e); + } + } }; ws.onerror = () => { diff --git a/server/test/controllers/api/v1/show/test_shows.py b/server/test/controllers/api/v1/show/test_shows.py index 6b8e27700..e70df019a 100644 --- a/server/test/controllers/api/v1/show/test_shows.py +++ b/server/test/controllers/api/v1/show/test_shows.py @@ -432,6 +432,13 @@ def test_delete_show_unauthenticated(self): with self._app.get_db().sessionmaker() as session: self.assertIsNotNone(session.get(Show, show_b_id)) + def test_delete_show_unauthenticated_nonexistent_show(self): + """Auth is checked before the show lookup, so existence is not leaked.""" + response = self.fetch( + "/api/v1/show?id=99999", method="DELETE", allow_nonstandard_methods=True + ) + self.assertEqual(401, response.code) + def test_delete_show_non_admin(self): """A logged-in non-admin cannot delete a show.""" show_b_id = self._create_show() @@ -443,7 +450,7 @@ def test_delete_show_non_admin(self): session.commit() token = self._app.jwt_service.create_access_token({"user_id": user_id}) response = self._delete(show_b_id, token=token) - self.assertIn(response.code, (401, 403)) + self.assertEqual(401, response.code) with self._app.get_db().sessionmaker() as session: self.assertIsNotNone(session.get(Show, show_b_id)) diff --git a/server/test/controllers/test_ws_controller.py b/server/test/controllers/test_ws_controller.py index dd575bdb6..5573553a5 100644 --- a/server/test/controllers/test_ws_controller.py +++ b/server/test/controllers/test_ws_controller.py @@ -16,7 +16,7 @@ from sqlalchemy import select from tornado.httpclient import HTTPRequest from tornado.testing import gen_test -from tornado.websocket import websocket_connect +from tornado.websocket import WebSocketClosedError, websocket_connect from controllers.ws_controller import WebSocketController from digi_server.logger import get_logger @@ -3695,6 +3695,31 @@ async def test_inbound_message_size_observed(self): self.assertGreaterEqual(self._message_count(), before + 2) +class TestWSOversizedMessage(DigiScriptTestCase): + @gen_test + async def test_message_over_limit_closes_connection(self): + """The server ends the connection when a message exceeds the size cap. + + The cap is Tornado's ``websocket_max_message_size`` (lowered here). + Tornado sends a 1009 close frame and then drops the socket while the + client is still uploading, so a client may observe 1009 or an abnormal + close; only the termination is asserted. + """ + limit = 1024 * 1024 + self._app.settings["websocket_max_message_size"] = limit + conn = await websocket_connect( + f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" + ) + try: + await conn.write_message("x" * (limit + 1024)) + except WebSocketClosedError: + pass # the server closed while the oversized frame was being sent + message = await conn.read_message() + while message is not None: + message = await conn.read_message() + self.assertIsNone(message) + + class TestWSHandlerMaps(DigiScriptTestCase): """Every op in the dispatch maps resolves to a handler method.""" diff --git a/server/test/digi_server/test_digi_server.py b/server/test/digi_server/test_digi_server.py index 9b80a3f7b..e272b0ad2 100644 --- a/server/test/digi_server/test_digi_server.py +++ b/server/test/digi_server/test_digi_server.py @@ -27,7 +27,7 @@ def test_debug_mode_is_opt_in(self): (Path(__file__).parents[2] / "main.py").read_text(encoding="utf-8") ) defaults = [ - kw.value.value + getattr(kw.value, "value", "") for node in ast.walk(tree) if isinstance(node, ast.Call) and getattr(node.func, "id", None) == "define" @@ -36,7 +36,12 @@ def test_debug_mode_is_opt_in(self): for kw in node.keywords if kw.arg == "default" ] - self.assertEqual([False], defaults) + self.assertEqual( + [False], + defaults, + "--debug must default to the literal False (update this test if the " + "default is computed)", + ) def test_traceback_not_returned_to_client(self): """Even with debug=True (as in the test app) no traceback is returned.""" @@ -58,6 +63,19 @@ def test_request_body_size_observed(self): self.fetch("/api/v1/nonexistent", method="POST", body="x" * 2000) self.assertEqual(before + 1, self._body_count(*labels)) + def test_unknown_http_method_does_not_create_new_series(self): + """Arbitrary method strings are reported as OTHER, keeping labels bounded.""" + before = self._body_count("ApiFallback", "OTHER") + for method in ("FOOA1", "FOOB2", "FOOC3"): + self.fetch( + "/api/v1/nonexistent", + method=method, + body="x" * 10, + allow_nonstandard_methods=True, + ) + self.assertEqual(before + 3, self._body_count("ApiFallback", "OTHER")) + self.assertEqual(0, self._body_count("ApiFallback", "FOOA1")) + def test_request_without_body_not_observed(self): """Body-less requests do not add to the size histogram.""" before = self._body_count("ApiFallback", "GET") diff --git a/server/utils/web/request_size_metrics.py b/server/utils/web/request_size_metrics.py index 56f039b9a..21e33ad92 100644 --- a/server/utils/web/request_size_metrics.py +++ b/server/utils/web/request_size_metrics.py @@ -9,6 +9,7 @@ from __future__ import annotations import functools +import inspect from prometheus_client import Histogram @@ -30,36 +31,62 @@ ) +_KNOWN_METHODS = frozenset({"GET", "POST", "PUT", "PATCH", "DELETE", "HEAD", "OPTIONS"}) + + def observe_http_request(handler) -> None: """Record the body size of a finished HTTP request, if it had a body. - The label is the handler class name (bounded), never the raw path. + Both labels are bounded: the handler class name (never the raw path) and + the HTTP method, with anything outside the standard set reported as + ``OTHER`` so a client cannot create unlimited series. :param handler: The finished Tornado ``RequestHandler``. """ size = len(handler.request.body or b"") if size: + method = handler.request.method http_request_body_bytes.labels( - type(handler).__name__, handler.request.method + type(handler).__name__, method if method in _KNOWN_METHODS else "OTHER" ).observe(size) class WSMessageSizeMetricsMixin: - """Observes the size of every message passed to a subclass's ``on_message``. + """Observes the size in bytes of every message passed to ``on_message``. ``on_message`` is wrapped when the subclass is created, so the subclass's - own method body needs no changes. + own method body needs no changes. The subclass must define an ``async`` + ``on_message`` directly in its class body; anything else fails at import + time rather than silently recording nothing. A subclass that overrides + ``on_message`` and calls ``super().on_message`` is observed once per + message, not twice. """ + _observing_ws_size = False + def __init_subclass__(cls, **kwargs): super().__init_subclass__(**kwargs) original = cls.__dict__.get("on_message") - if original is None: - return + if original is None or not inspect.iscoroutinefunction(original): + raise TypeError( + f"{cls.__name__} must define an async on_message to use " + "WSMessageSizeMetricsMixin" + ) @functools.wraps(original) async def on_message(self, message): - ws_message_bytes.observe(len(message)) - return await original(self, message) + if self._observing_ws_size: + return await original(self, message) + size = ( + len(message.encode("utf-8")) + if isinstance(message, str) + else len(message) + ) + ws_message_bytes.observe(size) + self._observing_ws_size = True + try: + return await original(self, message) + finally: + self._observing_ws_size = False cls.on_message = on_message From ce676e3ea0ecfc5f68b0a1e9317b9a8821acd197 Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Tue, 20 Oct 2026 13:21:18 +0100 Subject: [PATCH 5/6] Address review round 2: resync after 1009 reconnect, cover stability timer, control case for size-limit test Co-Authored-By: Claude Sonnet 5.5 --- .../useWebSocket.closeTooBig.test.ts | 41 ++++++++++++++++++- client-v3/src/composables/useWebSocket.ts | 7 ++-- server/test/controllers/test_ws_controller.py | 6 +++ 3 files changed, 49 insertions(+), 5 deletions(-) diff --git a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts index aa97196f2..53911d274 100644 --- a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts +++ b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts @@ -13,7 +13,7 @@ class FakeWebSocket { static CONNECTING = 0; static instances: FakeWebSocket[] = []; readyState = 3; - onopen: (() => void) | null = null; + onopen: (() => Promise | void) | null = null; onmessage: ((e: { data: string }) => void) | null = null; onclose: ((e?: { code: number }) => void) | null = null; onerror: (() => void) | null = null; @@ -46,6 +46,45 @@ describe('close code 1009', () => { vi.unstubAllGlobals(); }); + it('re-syncs the live session after reconnecting from a 1009 close', async () => { + const { useShowStore } = await import('@/stores/show'); + const showStore = useShowStore(); + showStore.currentSession = { id: 1 } as never; + const resync = vi.spyOn(showStore, 'getShowSessionData').mockResolvedValue(); + + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + vi.advanceTimersByTime(2100); + await FakeWebSocket.instances[1].onopen?.(); + + expect(resync).toHaveBeenCalledTimes(1); + expect(toast.success).toHaveBeenCalledWith('WebSocket reconnected after 1 attempt'); + }); + + it('forgets earlier 1009 closes once a connection has stayed up for 30s', async () => { + useWebSocket().connect(); + await FakeWebSocket.instances[0].onopen?.(); + vi.advanceTimersByTime(30100); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + // Count was cleared, so this is the first close again: 2s delay. + vi.advanceTimersByTime(2100); + expect(FakeWebSocket.instances).toHaveLength(2); + }); + + it('keeps the 1009 count when the connection was up for less than 30s', async () => { + useWebSocket().connect(); + FakeWebSocket.instances[0].onclose?.({ code: 1009 }); + vi.advanceTimersByTime(2100); + await FakeWebSocket.instances[1].onopen?.(); + vi.advanceTimersByTime(10000); + FakeWebSocket.instances[1].onclose?.({ code: 1009 }); + // Second consecutive close: 4s delay. + vi.advanceTimersByTime(3500); + expect(FakeWebSocket.instances).toHaveLength(2); + vi.advanceTimersByTime(600); + expect(FakeWebSocket.instances).toHaveLength(3); + }); + it('keeps backing off when authentication succeeds between closes', async () => { useWebSocket().connect(); FakeWebSocket.instances[0].onclose?.({ code: 1009 }); diff --git a/client-v3/src/composables/useWebSocket.ts b/client-v3/src/composables/useWebSocket.ts index 8ca6756eb..38e6d3d4e 100644 --- a/client-v3/src/composables/useWebSocket.ts +++ b/client-v3/src/composables/useWebSocket.ts @@ -188,12 +188,11 @@ function connect(): void { ws.onopen = async () => { try { - const wasErrored = errorCount > 0; + const attempts = Math.max(errorCount, tooBigCount); + const wasErrored = attempts > 0; wsStore.$patch({ isConnected: true }); if (wasErrored) { - toast.success( - `WebSocket reconnected after ${errorCount} attempt${errorCount > 1 ? 's' : ''}` - ); + toast.success(`WebSocket reconnected after ${attempts} attempt${attempts > 1 ? 's' : ''}`); } log.info('WebSocket connected'); if (stableTimer) clearTimeout(stableTimer); diff --git a/server/test/controllers/test_ws_controller.py b/server/test/controllers/test_ws_controller.py index 5573553a5..e9b9ed708 100644 --- a/server/test/controllers/test_ws_controller.py +++ b/server/test/controllers/test_ws_controller.py @@ -14,6 +14,7 @@ import pycrdt from sqlalchemy import select +from tornado import gen from tornado.httpclient import HTTPRequest from tornado.testing import gen_test from tornado.websocket import WebSocketClosedError, websocket_connect @@ -3710,6 +3711,11 @@ async def test_message_over_limit_closes_connection(self): conn = await websocket_connect( f"ws://127.0.0.1:{self.get_http_port()}/api/v1/ws" ) + # Control case: a message under the cap leaves the connection open. + await conn.write_message("x" * (limit - 1024)) + await gen.sleep(0.2) + conn.ping(b"") + self.assertIsNone(conn.close_code) try: await conn.write_message("x" * (limit + 1024)) except WebSocketClosedError: From 1748bd92124b916c3f345a5f79b06d962e3eb89d Mon Sep 17 00:00:00 2001 From: Tim Bradgate Date: Tue, 20 Oct 2026 13:30:52 +0100 Subject: [PATCH 6/6] Address review round 3: make 30s stability test exercise the reset, use asyncio.sleep Co-Authored-By: Claude Sonnet 5.5 --- .../src/composables/useWebSocket.closeTooBig.test.ts | 11 +++++++---- server/test/controllers/test_ws_controller.py | 3 +-- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts index 53911d274..cc2dcd563 100644 --- a/client-v3/src/composables/useWebSocket.closeTooBig.test.ts +++ b/client-v3/src/composables/useWebSocket.closeTooBig.test.ts @@ -63,12 +63,15 @@ describe('close code 1009', () => { it('forgets earlier 1009 closes once a connection has stayed up for 30s', async () => { useWebSocket().connect(); - await FakeWebSocket.instances[0].onopen?.(); - vi.advanceTimersByTime(30100); FakeWebSocket.instances[0].onclose?.({ code: 1009 }); - // Count was cleared, so this is the first close again: 2s delay. vi.advanceTimersByTime(2100); - expect(FakeWebSocket.instances).toHaveLength(2); + // Second connection stays up long enough to clear the earlier 1009 count. + await FakeWebSocket.instances[1].onopen?.(); + vi.advanceTimersByTime(30100); + FakeWebSocket.instances[1].onclose?.({ code: 1009 }); + // Count was cleared, so this is a first close again: 2s delay, not 4s. + vi.advanceTimersByTime(2100); + expect(FakeWebSocket.instances).toHaveLength(3); }); it('keeps the 1009 count when the connection was up for less than 30s', async () => { diff --git a/server/test/controllers/test_ws_controller.py b/server/test/controllers/test_ws_controller.py index e9b9ed708..2d2251f88 100644 --- a/server/test/controllers/test_ws_controller.py +++ b/server/test/controllers/test_ws_controller.py @@ -14,7 +14,6 @@ import pycrdt from sqlalchemy import select -from tornado import gen from tornado.httpclient import HTTPRequest from tornado.testing import gen_test from tornado.websocket import WebSocketClosedError, websocket_connect @@ -3713,7 +3712,7 @@ async def test_message_over_limit_closes_connection(self): ) # Control case: a message under the cap leaves the connection open. await conn.write_message("x" * (limit - 1024)) - await gen.sleep(0.2) + await asyncio.sleep(0.2) conn.ping(b"") self.assertIsNone(conn.close_code) try: