From c1ce0b7b04f2ee2fbc3d5be643ecb1fdf5a3534a Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 15:49:29 -0400 Subject: [PATCH 1/4] fix(web): two api_v3 paths called names that no longer exist (#625) The Pixlet editor stop route restarts the display after a SIGKILL with _run_systemctl_command, which starlark.py never imported (since #554). The Starlark device-location resolver fell back to _ensure_cache_manager, which #609 deleted; the resolver already accepts no cache manager. Both raised NameError on the rare path that reaches them. pyflakes finds no other undefined names in src/ or web_interface/. Co-authored-by: Claude Opus 5.5 --- .../test_api_v3_names_resolve.py | 25 +++++++++++++++++++ web_interface/blueprints/api_v3/__init__.py | 2 +- web_interface/blueprints/api_v3/starlark.py | 1 + 3 files changed, 27 insertions(+), 1 deletion(-) create mode 100644 test/web_interface/test_api_v3_names_resolve.py diff --git a/test/web_interface/test_api_v3_names_resolve.py b/test/web_interface/test_api_v3_names_resolve.py new file mode 100644 index 00000000..6b6e6c1c --- /dev/null +++ b/test/web_interface/test_api_v3_names_resolve.py @@ -0,0 +1,25 @@ +"""Names two rarely-run api_v3 paths call must exist. + +Both slipped through because nothing exercised them: the Pixlet editor's +stop route only restarts the display after a SIGKILL, and the Starlark +device-location resolver only builds a cache manager when the web app has +not set one. Either raised NameError when it finally ran. +""" + +from unittest.mock import patch + +from test._api_v3_test_helpers import api_v3_module # noqa: F401 + + +def test_the_editor_stop_route_can_restart_the_display(): + from web_interface.blueprints.api_v3 import starlark + + assert callable(starlark._run_systemctl_command) + + +def test_the_device_location_resolver_builds_without_a_cache_manager(api_v3_module): + pkg = api_v3_module + with patch.object(pkg.api_v3, 'cache_manager', None, create=True), \ + patch.object(pkg, '_starlark_device_location', None): + resolver = pkg._get_starlark_device_location() + assert resolver.cache_manager is None diff --git a/web_interface/blueprints/api_v3/__init__.py b/web_interface/blueprints/api_v3/__init__.py index 6d26a980..29a9f4e4 100644 --- a/web_interface/blueprints/api_v3/__init__.py +++ b/web_interface/blueprints/api_v3/__init__.py @@ -1712,7 +1712,7 @@ def _get_starlark_device_location() -> DeviceLocationResolver: global _starlark_device_location if _starlark_device_location is None: _starlark_device_location = DeviceLocationResolver( - getattr(api_v3, 'cache_manager', None) or _ensure_cache_manager(), logger) + getattr(api_v3, 'cache_manager', None), logger) return _starlark_device_location diff --git a/web_interface/blueprints/api_v3/starlark.py b/web_interface/blueprints/api_v3/starlark.py index 856de4a4..08d592c7 100644 --- a/web_interface/blueprints/api_v3/starlark.py +++ b/web_interface/blueprints/api_v3/starlark.py @@ -11,6 +11,7 @@ from web_interface.blueprints.api_v3 import ( _PIXLET_EDITOR_DEFAULT_TIMEOUT, _PIXLET_EDITOR_MAX_TIMEOUT, _PIXLET_EDITOR_SCRIPT, _PIXLET_EDITOR_STATE, _clear_pixlet_editor_state, _find_pixlet_binary, _install_star_file, _pixlet_editor_alive, + _run_systemctl_command, _pixlet_editor_status, _read_pixlet_editor_state, _STARLARK_APPS_DIR, _standalone_render_starlark_app, _starlark_github_token, _starlark_manifest_lock, From 82f3a3a3e4053d352cbefd054b922432434f7ecf Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 15:49:51 -0400 Subject: [PATCH 2/4] fix(redaction): make credential redaction linear, not quadratic (#631) * fix(redaction): make URL-userinfo redaction linear, not quadratic _REDACT_URL_USERINFO could start a match at every letter of a run of scheme characters, and each attempt read to the end of the run looking for `://`. On a long unbroken run of letters or digits (a hex digest, an ID, part of a response body) that is quadratic: 1.6s for 20k characters. The display service redacts every message, stack trace and context value it publishes in the error snapshot, holding the aggregator lock, and re.sub holds the GIL for the whole call, so one such exception stalled every thread, render loop included (~0.5s measured for 20k chars of hex). It also made test_snapshot_stays_small the slowest test in the suite by far: 142s of a 383s run, 139s of it in this one regex. A match may now only start where a run of scheme characters starts (negative lookbehind). Leading digits and `+.-` are captured in group 1 so the substitution restores them, and the scheme still has to start with a letter, so what gets redacted is unchanged: old and new output were identical on 300k fuzzed inputs. 20k chars now take ~0.5ms, 200k ~6ms, and test_snapshot_stays_small takes 0.8s. test/test_redaction.py pins the exact output for schemes that begin after digits or `+.-`, and bounds 50k-character runs at 1s; against the old pattern those timing tests fail at 3-11s each. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01KMXdS2S4NXTJ8ET96GymhK * fix(redaction): make Authorization-header redaction linear too _REDACT_AUTH_HEADER matched the value's opening as `\s*["\']?\s*`: two `\s*` separated only by an optional quote. With no quote, a whitespace run could be split between them in every possible way, and when no credential followed (end of text, or `,` `"` `<` ...) the engine tried them all before giving up: quadratic, 8s for `authorization:` and 20k spaces, 17s with `Proxy-Authorization:` (tried again at the inner `authorization`). Same stall as the URL pattern: re.sub holds the GIL, and the display service redacts everything it publishes. The quote and the whitespace after it are now one optional unit, `\s*(?:["\']\s*)?`, which matches the same strings with only one way to split them. Output is identical to the old pattern on 300k fuzzed inputs; 20k spaces now take ~1.6ms. A scan of all three redaction patterns over prefix/run/suffix shapes finds none left that scales superlinearly. test/test_redaction.py pins exact output for quoted, tabbed, multi-line and credential-less headers, and bounds header + 20k whitespace at 1s; against the previous pattern those fail at 8-17s each. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01KMXdS2S4NXTJ8ET96GymhK --------- Co-authored-by: Claude --- CHANGELOG.md | 7 +++ src/redaction.py | 19 +++++-- test/test_redaction.py | 110 +++++++++++++++++++++++++++++++++++++++++ 3 files changed, 133 insertions(+), 3 deletions(-) create mode 100644 test/test_redaction.py diff --git a/CHANGELOG.md b/CHANGELOG.md index f136d44a..c2ae2dc5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -120,6 +120,13 @@ floor on the release that ships them): when the count is only known to the display service. - The Logs tab has a **Plugin errors** panel: per-plugin counts, repeating errors and a Clear button. +- Credential redaction in exception text (`src/redaction.py`) takes time + proportional to the text, not its square. Two patterns were quadratic: URL + `user:password@`, on a long unbroken run of letters or digits (a hex digest, + an ID), and `Authorization:` followed by a long run of whitespace. Either + used to stall every thread of the display service for up to seconds each + time the snapshot was published: about 0.5s for 20k characters of hex, 8s + for 20k spaces. What gets redacted is unchanged. ### Removed diff --git a/src/redaction.py b/src/redaction.py index b84bf1b1..a1294309 100644 --- a/src/redaction.py +++ b/src/redaction.py @@ -24,8 +24,13 @@ _REDACT_CREDENTIAL = re.compile( # silently leak the ones nobody thought of. Not covered by the generic pattern # above, whose value part stops at whitespace and so would keep the credential # once a space follows the scheme. +# +# The opening quote and the whitespace after it are one optional unit. Written +# `\s*["\']?\s*`, a whitespace run with no quote in it could be split between +# the two `\s*` in every possible way, and a header with no credential after +# it tried them all: quadratic, 8s for 20k spaces. _REDACT_AUTH_HEADER = re.compile( - r'((?:proxy-)?authorization["\']?\s*[=:]\s*["\']?\s*' + r'((?:proxy-)?authorization["\']?\s*[=:]\s*(?:["\']\s*)?' r'(?:[A-Za-z][\w.+-]*[ \t]+)?)' # optional scheme name, kept r'([^\s,"\'<>}]+)', # the credential, redacted re.IGNORECASE, @@ -34,8 +39,16 @@ _REDACT_AUTH_HEADER = re.compile( # Credentials embedded in a URL: https://user:password@host. requests quotes # the full URL in its exceptions, so this is a realistic leak. The username is # kept -- it identifies which account failed without being the secret. -_REDACT_URL_USERINFO = re.compile(r'([a-z][a-z0-9+.-]*://[^/\s:@]+:)([^/\s@]+)(@)', - re.IGNORECASE) +# +# A match may only start where a run of scheme characters starts. Unanchored, +# `[a-z][a-z0-9+.-]*://` was tried from every letter of a long run (a hex +# digest, an ID, a blob of response body), each attempt reading to the end of +# the run: quadratic, 1.6s for 20k characters, all of it holding the GIL. +# Leading digits and `+.-` sit inside group 1 so the substitution puts them +# back; the scheme proper still has to start with a letter. +_REDACT_URL_USERINFO = re.compile( + r'((? str: diff --git a/test/test_redaction.py b/test/test_redaction.py new file mode 100644 index 00000000..5f59d696 --- /dev/null +++ b/test/test_redaction.py @@ -0,0 +1,110 @@ +"""redact_credentials must stay linear in the length of its input. + +Regressions under test, both quadratic regexes in src/redaction.py: + +- The URL-userinfo pattern (`scheme://user:password@`) could start a match at + every letter of a run of scheme characters, and each attempt read to the end + of the run looking for `://`: 1.6s for a 20k-character run. +- The Authorization-header pattern had two `\\s*` separated only by an + optional quote, so a header followed by whitespace and no credential tried + every split of that whitespace between them: 8s for 20k spaces. + +The display service redacts every message, stack trace and context value it +publishes in the error snapshot, and re.sub holds the GIL throughout, so an +exception quoting a hex digest or a long ID stalled the render loop with it. +test_error_snapshot_cross_process.py's snapshot-size test spent 140s here. + +The fixed patterns have to redact exactly what the old ones did. +""" + +import time + +import pytest + +from src.redaction import redact_credentials + +# Each timed input took seconds before the fix and takes about a millisecond +# after it; the bound leaves CI plenty of headroom while still failing on a +# quadratic pattern. +_TIME_LIMIT = 1.0 + + +def _timed(text): + start = time.perf_counter() + result = redact_credentials(text) + return result, time.perf_counter() - start + + +class TestUrlUserinfo: + @pytest.mark.parametrize("text,expected", [ + ("401 for https://user:hunter2@example.com/api", + "401 for https://user:@example.com/api"), + ("HTTPS://USER:HUNTER2@EXAMPLE.COM", + "HTTPS://USER:@EXAMPLE.COM"), + ("git+ssh://deploy:hunter2@host/repo", + "git+ssh://deploy:@host/repo"), + # The scheme starts after digits or +.- in the same run. Those + # characters must survive, and the password must still go. + ("1http://user:hunter2@host", "1http://user:@host"), + ("+.-http://user:hunter2@host", "+.-http://user:@host"), + ("a1+http://user:hunter2@host", "a1+http://user:@host"), + ("see a://u:first@b and c://v:second@d", + "see a://u:@b and c://v:@d"), + ]) + def test_password_is_redacted_and_the_rest_kept(self, text, expected): + assert redact_credentials(text) == expected + + def test_a_url_without_a_password_is_untouched(self): + text = "GET https://user@example.com/path failed" + assert redact_credentials(text) == text + + +class TestAuthorizationHeader: + @pytest.mark.parametrize("text,expected", [ + ("Authorization: Bearer eyJ.SECRET.sig", "Authorization: Bearer "), + ("Proxy-Authorization: Basic dXNlcg==", "Proxy-Authorization: Basic "), + ("authorization: barecredential", "authorization: "), + # Whitespace and an opening quote around the value, in either order. + ('authorization=" Bearer tok"', 'authorization=" Bearer "'), + ("authorization: ' tok'", "authorization: ' '"), + ("authorization:\n\tBearer tok", "authorization:\n\tBearer "), + ]) + def test_credential_is_redacted_and_the_rest_kept(self, text, expected): + assert redact_credentials(text) == expected + + @pytest.mark.parametrize("text", ["authorization: ", "authorization: , next"]) + def test_a_header_without_a_credential_is_untouched(self, text): + assert redact_credentials(text) == text + + +class TestLinearTime: + @pytest.mark.parametrize("unit", ["x", "0123456789abcdef", "1a", "a+", "1"]) + def test_long_scheme_character_runs(self, unit): + text = (unit * 50_000)[:50_000] + result, elapsed = _timed(text) + assert result == text + assert elapsed < _TIME_LIMIT, f"{elapsed:.2f}s to redact {len(text)} chars of {unit!r}" + + def test_a_credential_after_a_long_run_is_still_found(self): + run = "ab12" * 10_000 + result, elapsed = _timed(f"{run} https://user:hunter2@example.com") + assert result == f"{run} https://user:@example.com" + assert elapsed < _TIME_LIMIT + + @pytest.mark.parametrize("header,whitespace", [ + ("authorization:", " "), + ("Proxy-Authorization:", "\t"), + ("authorization=", "\n"), + ]) + def test_a_header_followed_by_long_whitespace(self, header, whitespace): + text = header + whitespace * 20_000 + "," + result, elapsed = _timed(text) + assert result == text + assert elapsed < _TIME_LIMIT, ( + f"{elapsed:.2f}s to redact {header!r} and {len(text) - len(header)} more chars") + + def test_a_credential_after_long_whitespace_is_still_found(self): + gap = " " * 20_000 + result, elapsed = _timed(f"authorization:{gap}Bearer tok") + assert result == f"authorization:{gap}Bearer " + assert elapsed < _TIME_LIMIT From 5baf983fe0b2b69114bdf221f4f9009bd6fa74e1 Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 15:50:33 -0400 Subject: [PATCH 3/4] docs(scroll): explain the tear across the middle on fast scrolls (#620) * docs(scroll): explain the tear across the middle on fast scrolls A 1:32-multiplexed 64-row panel lights row 31 almost a whole refresh after row 32, so fast scrolls show a sideways offset at mid-height of about speed x refresh period. Documents the cause, how to read the real refresh rate (show_refresh_rate prints with a carriage return), what was measured on a single-chain 2x128x64 Pi 4 (pwm_bits, gpio_slowdown and an uncapped refresh barely help; gpio_slowdown 2 glitches), and the fix that does help: fewer pixels per output via parallel chains. Co-Authored-By: Claude Opus 5.5 * docs(scroll): limit the 1:32 row-pair explanation to panels that scan that way Co-Authored-By: Claude Opus 5.5 --------- Co-authored-by: Claude Opus 5.5 --- docs/SCROLL_PERFORMANCE.md | 70 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 70 insertions(+) diff --git a/docs/SCROLL_PERFORMANCE.md b/docs/SCROLL_PERFORMANCE.md index 82e9f912..b588adfc 100644 --- a/docs/SCROLL_PERFORMANCE.md +++ b/docs/SCROLL_PERFORMANCE.md @@ -303,6 +303,76 @@ journalctl -u ledmatrix --since "-5min" --no-pager | grep -iE "px/s|px/frame" If a plugin logs its scroll config **twice** with different modes, the second line is what is running. +--- + +## A tear across the middle on fast scrolls + +**Symptom:** while text scrolls, the top and bottom halves of the panel look +shifted sideways against each other along a horizontal line at mid-height, and +the shift grows with scroll speed. It shows most in Vegas mode at high speed. + +**It is the panel's scan, not the software.** The measured panel, like most +64-row panels, is multiplexed 1:32 (some panels of the same size scan +differently, so check yours): it lights two rows at a time, one from each half +(row 0 with row 32, row 1 with row 33, …), stepping down both halves together +once per refresh. So row 31, +the last row of the top half, lights almost a whole refresh period after row 32 +right below it. Your eye follows moving text, and moving content that lights at +different times lands in different places, so the two rows meet with an offset +of roughly + +``` +offset ≈ scroll speed × refresh period +``` + +Each frame already reaches the panel whole (`SwapOnVSync` swaps complete frames +between refreshes), so there is nothing to fix in the render path; the shift is +created inside a single refresh. Other panel heights show it too, at the point +where their two scan halves meet. + +On the 2×128×64 chain above, which refreshes at about 130 Hz flat out +(7.7 ms per pass): + +| scroll speed | offset at the midline | +|---|---| +| 50 px/s (Vegas default) | ~0.4 px | +| 100 px/s | ~0.8 px | +| 150 px/s | ~1.2 px, plainly visible | + +### What changes it + +Only a shorter scan period (a faster refresh) or a slower scroll. Measure what +the panel actually achieves first. The library prints the rate with a carriage +return and no newline, so read it from the raw journal: + +```bash +# set display.hardware.show_refresh_rate to true (web UI, Display tab), restart, then: +journalctl -u ledmatrix --since "-1min" --no-pager -o cat --all | grep -a -oE "[0-9.]+Hz" | tail -5 +``` + +Turn it off again afterwards. Measured on that panel (Pi 4, single chain), +changing one setting at a time from `pwm_bits: 7`, `gpio_slowdown: 3`: + +| change | refresh, uncapped | notes | +|---|---|---| +| none | ~130 Hz | the ceiling for this wiring | +| `pwm_bits: 6` | ~138 Hz | barely faster, and half the colour depth | +| `gpio_slowdown: 2` | ~130 Hz | no faster, **and visible glitching**; keep 3 | +| `limit_refresh_rate_hz: 0` | ~130 Hz | Vegas dropped from 100 to 72–95 fps as the refresh thread took more CPU | + +None of these helps much, because the time goes into shifting each row's pixels +out: a 2×128 chain pushes 256 pixels per row down one output. What does help is +**fewer pixels per output**. On a bonnet with more than one output (the +`regular` and `classic` mappings have 3; `adafruit-hat` has 1), put each panel +on its own output and set `parallel` to the number of outputs used and +`chain_length` to the panels per output, for example `parallel: 2`, +`chain_length: 1` for two panels. Each refresh then shifts half the data, which +should roughly double the refresh rate and halve the offset. That is a cable +change, so measure again afterwards. + +Short of rewiring, keep fast scrolls moderate: at the default 50 px/s the +offset is under half a pixel. + ## Rebuilding the binding ```bash From ddf5f085a56b9c6664dad82752c206540e22523f Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 15:50:50 -0400 Subject: [PATCH 4/4] perf(cache): tell a stale record from its header instead of parsing it (#633) The sports plugins cache whole season schedules: 53MB for MLB, 18MB for NHL, 17MB for NCAA baseball. On a Pi 4, orjson.loads of the MLB file takes ~1.8s with the GIL held, and every thread in the display service waits -- the stall watchdog caught the render thread frozen 0.5-1.3s with the interpreter itself blocked, right on these reads. When a season record expired, DiskCache.get paid that whole parse only to find the timestamp too old and throw the result away. CacheManager.set now writes timestamp and ttl ahead of the data, and DiskCache.get reads them from the first 256 bytes of the file, applying the same rule as before (a per-entry ttl wins over max_age; no limit means never stale). A record that is stale is refused without being parsed. Files in the old layout, and records from other writers, don't match the header and are parsed in full as before. Also: ESPN responses in the background data service and espn_dates are parsed with orjson when it is installed (src/common/json_body.py). The stdlib parser behind response.json() takes 3.1s on the MLB season against orjson's 1.8s, both with the GIL held. espn_dates imports it with a fallback, since plugins bundle copies of that module for older cores. Co-authored-by: Claude Opus 5.5 --- src/background_data_service.py | 3 +- src/cache/disk_cache.py | 43 ++++++++++++ src/cache_manager.py | 14 ++-- src/common/espn_dates.py | 12 +++- src/common/json_body.py | 29 ++++++++ test/test_cache_stale_header.py | 118 ++++++++++++++++++++++++++++++++ 6 files changed, 211 insertions(+), 8 deletions(-) create mode 100644 src/common/json_body.py create mode 100644 test/test_cache_stale_header.py diff --git a/src/background_data_service.py b/src/background_data_service.py index 22989a56..a41aef45 100644 --- a/src/background_data_service.py +++ b/src/background_data_service.py @@ -26,6 +26,7 @@ from enum import Enum from concurrent.futures import ThreadPoolExecutor import pytz from src.cache_manager import CacheManager +from src.common.json_body import response_json from src.common.espn_dates import ( RANGE_RETRY_SECONDS, _note_range_rejected, @@ -389,7 +390,7 @@ class BackgroundDataService: response.raise_for_status() else: response.raise_for_status() - data = response.json() + data = response_json(response) # Validate data structure if not isinstance(data, dict): diff --git a/src/cache/disk_cache.py b/src/cache/disk_cache.py index 87c3d7a9..fb776b56 100644 --- a/src/cache/disk_cache.py +++ b/src/cache/disk_cache.py @@ -7,6 +7,7 @@ Handles persistent disk-based caching with atomic writes and error recovery. import json import math import os +import re import stat import time import tempfile @@ -98,6 +99,40 @@ def _replace_nonfinite(obj: Any) -> Any: # deleted. Both halves are covered by test/test_cache_nonfinite_floats.py. +#: Enough of a record to hold its header: ``{"timestamp":,"ttl":,``. +_HEAD_BYTES = 256 + +#: A record written with its header first (CacheManager.set does). Anything +#: else -- older files with "data" first, records from other writers -- does not +#: match and is parsed in full, as before. +_HEAD_RE = re.compile( + rb'\A\s*\{\s*"timestamp"\s*:\s*(-?[0-9][0-9.eE+-]*)\s*' + rb'(?:,\s*"ttl"\s*:\s*(-?[0-9][0-9.eE+-]*))?\s*[,}]' +) + + +def _stale_from_head(head: bytes, max_age: Optional[int], now: float) -> bool: + """True when a record's header alone shows it has expired. + + Mirrors the expiry rule in DiskCache.get: a per-entry ttl wins over the + caller's max_age, and no limit at all means never stale. False whenever the + header cannot be read, so the full parse decides as it always did. + """ + match = _HEAD_RE.match(head) + if not match: + return False + try: + timestamp = float(match.group(1)) + limit = max_age + if match.group(2) is not None: + ttl = float(match.group(2)) + if ttl >= 0: + limit = ttl + except ValueError: + return False + return limit is not None and (now - timestamp) > limit + + if orjson is not None: # Encoding the cache record dominated the background fetch worker: on a # Pi 4, stdlib json.dumps runs ~12ms per MB and holds the GIL for all of @@ -266,6 +301,14 @@ class DiskCache: try: with self._lock: with open(cache_path, 'rb') as f: + # Decide staleness from the header before paying for the + # parse. A stale read is the common case for the biggest + # records (a season schedule is re-fetched when its cache + # expires), and parsing 53MB to throw it away held the GIL + # for ~1.8s -- a visible freeze on the panel. + if _stale_from_head(f.read(_HEAD_BYTES), max_age, time.time()): + return None + f.seek(0) record = _loads(f.read()) # Determine record timestamp (prefer embedded, else file mtime) diff --git a/src/cache_manager.py b/src/cache_manager.py index 4d80c986..d064a37f 100644 --- a/src/cache_manager.py +++ b/src/cache_manager.py @@ -522,8 +522,9 @@ class CacheManager: def update_cache(self, data_type: str, data: Dict[str, Any]) -> bool: """Update cache with new data.""" cache_data = { + # Header first; see DiskCache's stale check. + 'timestamp': time.time(), 'data': data, - 'timestamp': time.time() } return self.save_cache(data_type, cache_data) @@ -556,12 +557,15 @@ class CacheManager: from the key and is only a fallback for entries that did not say. Omit it to keep that inferred behaviour. """ - cache_data = { - 'data': data, - 'timestamp': time.time() - } + # timestamp and ttl before data, so they are the first bytes on disk: + # DiskCache.get reads them from the head of the file and can call a + # record stale without parsing it. That matters for the big ones -- a + # whole MLB season is 53MB and ~1.8s of orjson.loads with the GIL held, + # paid in full only to learn the record had expired. + cache_data: Dict[str, Any] = {'timestamp': time.time()} if ttl is not None: cache_data['ttl'] = ttl + cache_data['data'] = data self.save_cache(key, cache_data) @deprecated("3.7.0") diff --git a/src/common/espn_dates.py b/src/common/espn_dates.py index 9be705d1..bda7e86a 100644 --- a/src/common/espn_dates.py +++ b/src/common/espn_dates.py @@ -39,6 +39,14 @@ from datetime import date, timedelta from functools import partial from typing import Any, Dict, List, Optional, Tuple +try: + from src.common.json_body import response_json +except ImportError: + # Plugins bundle copies of this module for older cores, which predate + # json_body; the stdlib parse is what those cores always used. + def response_json(response: Any) -> Any: + return response.json() + # Above this, ESPN returns a truncated list instead of an error. See module # docstring: 500 is the largest value measured to return complete data. ESPN_MAX_LIMIT = 500 @@ -194,7 +202,7 @@ def _fetch_one_chunk( timeout=timeout, ) response.raise_for_status() - return response.json() + return response_json(response) except Exception as exc: # noqa: BLE001 - see docstring if logger: logger.warning("ESPN chunk %s failed, skipping it: %s", chunk, exc) @@ -371,4 +379,4 @@ def fetch_espn_scoreboard( if data is not None: return data response.raise_for_status() - return response.json() + return response_json(response) diff --git a/src/common/json_body.py b/src/common/json_body.py new file mode 100644 index 00000000..fb89301d --- /dev/null +++ b/src/common/json_body.py @@ -0,0 +1,29 @@ +"""Parse an HTTP response body as JSON, with orjson when it is installed. + +``requests``' ``response.json()`` uses the stdlib parser. For the payloads the +sports plugins fetch -- a season schedule is tens of MB -- that runs ~1.7x +slower than orjson on a Pi 4 (3.1s against 1.8s for the 53MB MLB season), and +both hold the GIL for the whole parse, which freezes the display for as long. +Nothing else changes: the result is the same Python objects. +""" + +from __future__ import annotations + +from typing import Any + +try: + import orjson +except ImportError: # optional dependency; see docs/SCROLL_PERFORMANCE.md + orjson = None + + +def response_json(response: Any) -> Any: + """``response.json()``, parsed by orjson when available.""" + body = getattr(response, "content", None) + if orjson is None or not isinstance(body, (bytes, bytearray)): + return response.json() + try: + return orjson.loads(body) + except orjson.JSONDecodeError: + # Let requests raise its usual error, with its usual message. + return response.json() diff --git a/test/test_cache_stale_header.py b/test/test_cache_stale_header.py new file mode 100644 index 00000000..026b982d --- /dev/null +++ b/test/test_cache_stale_header.py @@ -0,0 +1,118 @@ +"""A stale cache record is recognised from its header, without parsing it. + +The sports plugins cache whole season schedules -- 53MB for MLB, 18MB for NHL. +When one expired, DiskCache.get parsed all of it (~1.8s of orjson.loads on a +Pi 4, GIL held, the whole display frozen) only to find the timestamp too old +and throw the result away. CacheManager.set now writes timestamp and ttl ahead +of the data, and DiskCache.get reads them from the first bytes of the file. +""" + +import json +import time +from types import SimpleNamespace + +import pytest + +from src.cache import disk_cache as disk_cache_module +from src.cache.disk_cache import DiskCache, _stale_from_head +from src.common import json_body + + +@pytest.fixture +def disk(tmp_path): + return DiskCache(cache_dir=str(tmp_path)) + + +@pytest.fixture +def parses(monkeypatch): + """Count full parses of cache files.""" + calls = [] + real = disk_cache_module._loads + + def counting(raw): + calls.append(len(raw)) + return real(raw) + + monkeypatch.setattr(disk_cache_module, "_loads", counting) + return calls + + +def _header_first(age=0.0, ttl=None, events=100): + record = {"timestamp": time.time() - age} + if ttl is not None: + record["ttl"] = ttl + record["data"] = {"events": [{"id": n, "name": "x" * 50} for n in range(events)]} + return record + + +def test_cache_manager_writes_the_header_first(monkeypatch): + from src.cache_manager import CacheManager + written = {} + manager = CacheManager.__new__(CacheManager) + monkeypatch.setattr(manager, "save_cache", + lambda key, record: written.update({key: record}), + raising=False) + CacheManager.set(manager, "k", {"events": []}, ttl=60) + assert list(written["k"]) == ["timestamp", "ttl", "data"] + CacheManager.set(manager, "k", {"events": []}) + assert list(written["k"]) == ["timestamp", "data"] + + +def test_a_stale_record_is_not_parsed(disk, parses): + disk.set("season", _header_first(age=600)) + assert disk.get("season", max_age=300) is None + assert parses == [] + + +def test_a_fresh_record_is_parsed_and_returned(disk, parses): + disk.set("season", _header_first(age=10)) + record = disk.get("season", max_age=300) + assert record["data"]["events"][0]["id"] == 0 + assert len(parses) == 1 + + +def test_the_entry_ttl_wins_over_max_age(disk, parses): + disk.set("long", _header_first(age=600, ttl=3600)) + assert disk.get("long", max_age=300) is not None # ttl says fresh + disk.set("short", _header_first(age=60, ttl=30)) + parses.clear() + assert disk.get("short", max_age=300) is None # ttl says stale + assert parses == [] + + +def test_no_limit_means_never_stale(disk): + disk.set("forever", _header_first(age=10 ** 7)) + assert disk.get("forever", max_age=None) is not None + + +def test_older_files_with_data_first_still_work(disk, parses): + # Records written before the header moved: parsed in full, as before. + disk.set("legacy_fresh", {"data": {"v": 1}, "timestamp": time.time()}) + disk.set("legacy_stale", {"data": {"v": 1}, "timestamp": time.time() - 600}) + assert disk.get("legacy_fresh", max_age=300)["data"] == {"v": 1} + assert disk.get("legacy_stale", max_age=300) is None + assert len(parses) == 2 + + +@pytest.mark.parametrize("head, stale", [ + (b'{"timestamp":100.0,"data":{}}', True), + (b'{"timestamp": 100.0, "ttl": 1000, "data": {}}', False), # stdlib spacing + (b'{"timestamp":1e2,"ttl":5,"data":1}', True), + (b'{"timestamp":100.0}', True), + (b'{"data":{},"timestamp":100.0}', False), # unknown layout + (b'{"timestamp":"100.0","data":{}}', False), # string: parse it + (b'', False), +]) +def test_reading_the_header(head, stale): + assert _stale_from_head(head, 300, now=1000.0) is stale + + +def test_response_json_prefers_orjson_and_falls_back(): + payload = {"events": [1, 2, 3]} + response = SimpleNamespace(content=json.dumps(payload).encode(), + json=lambda: pytest.fail("used the slow path")) + if json_body.orjson is None: + pytest.skip("orjson not installed") + assert json_body.response_json(response) == payload + # A response object without bytes content (a test double) still works. + assert json_body.response_json(SimpleNamespace(json=lambda: payload)) == payload