Merge branch 'main' of https://github.com/ChuckBuilds/LEDMatrix into fix/plugin-update-keeps-local-files

# Conflicts:
#	test/test_on_demand_live_and_restore.py

test/test_display_hold_report.py

@@ -0,0 +1,142 @@
+"""The report of a scrolling screen held by its plugin's update().
+
+While a plugin's update() runs it holds the plugin's lock, and its screen's
+frames are skipped -- on a scroller, a frozen strip -- with nothing logged.
+_note_display_hold times each such run and reports one of
+DISPLAY_HOLD_REPORT_SECONDS or more.
+"""
+
+import threading
+import types
+from unittest.mock import MagicMock
+
+import pytest
+
+
+class _Clock:
+    """display_controller's clock: moves only when run() sleeps or a test says."""
+
+    def __init__(self, start=10_000.0):
+        self.t = start
+
+    def now(self):
+        return self.t
+
+    def sleep(self, seconds):
+        self.t += max(seconds, 0.0005)
+
+    def module(self):
+        return types.SimpleNamespace(time=self.now, monotonic=self.now,
+                                     perf_counter=self.now, sleep=self.sleep)
+
+
+@pytest.fixture
+def clock(monkeypatch):
+    c = _Clock()
+    monkeypatch.setattr("src.display_controller.time", c.module())
+    return c
+
+
+class _Locks:
+    """get_plugin_lock for one plugin, whose lock the test can hold."""
+
+    def __init__(self):
+        self.lock = threading.Lock()
+
+    def __call__(self, plugin_id):
+        return self.lock
+
+
+@pytest.fixture
+def held(test_display_controller):
+    c = test_display_controller
+    locks = _Locks()
+    c.plugin_manager.get_plugin_lock = locks
+    c.plugin_manager._warn_rate_limited = MagicMock()
+    c.plugin_manager.health_tracker = MagicMock()
+    c._display_hold = None
+    return c, locks.lock
+
+
+def _plugin(plugin_id):
+    p = MagicMock()
+    p.plugin_id = plugin_id
+    p.display.return_value = True
+    return p
+
+
+class TestTheDisplayHoldReport:
+    def test_a_long_hold_is_reported_when_it_ends(self, held, clock):
+        c, lock = held
+        ticker = _plugin("ticker")
+        lock.acquire()                         # update() running
+        assert c._display_once(ticker, "ticker", False, report_hold=True) is True
+        clock.t += 0.2
+        assert c._display_once(ticker, "ticker", False, report_hold=True) is True
+        assert ticker.display.call_count == 0
+        c.plugin_manager._warn_rate_limited.assert_not_called()
+        clock.t += 0.2
+        lock.release()                         # update() done
+        c._display_once(ticker, "ticker", False, report_hold=True)
+        assert ticker.display.call_count == 1
+        key, message, plugin_id, ms = c.plugin_manager._warn_rate_limited.call_args[0]
+        assert key == "display-hold:ticker" and plugin_id == "ticker"
+        assert "held" in message and ms == pytest.approx(400.0)
+        c.plugin_manager.health_tracker.record_busy_skip.assert_called_once_with(
+            "ticker", "display hold", pytest.approx(0.4))
+
+    def test_a_short_hold_is_not(self, held, clock):
+        c, lock = held
+        ticker = _plugin("ticker")
+        lock.acquire()
+        c._display_once(ticker, "ticker", False, report_hold=True)
+        clock.t += 0.1
+        lock.release()
+        c._display_once(ticker, "ticker", False, report_hold=True)
+        c.plugin_manager._warn_rate_limited.assert_not_called()
+        c.plugin_manager.health_tracker.record_busy_skip.assert_not_called()
+
+    def test_a_hold_that_ends_on_another_plugins_screen_is_not_blamed_on_it(
+            self, held, clock):
+        c, lock = held
+        lock.acquire()
+        c._display_once(_plugin("ticker"), "ticker", False, report_hold=True)
+        clock.t += 1.0
+        lock.release()
+        c._display_once(_plugin("clock"), "clock", False, report_hold=True)
+        c.plugin_manager._warn_rate_limited.assert_not_called()
+        assert c._display_hold is None
+
+    def test_frames_that_draw_report_nothing(self, held, clock):
+        c, _lock = held
+        ticker = _plugin("ticker")
+        for _ in range(5):
+            c._display_once(ticker, "ticker", False, report_hold=True)
+            clock.t += 0.5
+        c.plugin_manager._warn_rate_limited.assert_not_called()
+
+    def test_the_1hz_loop_reports_no_holds(self, held, clock):
+        # A static screen's frames are a second apart: one skipped frame is
+        # not a measured hold, and nothing on the panel froze. (On ledpi the
+        # first version reported every such skip as "held 1000 ms".)
+        c, lock = held
+        board = _plugin("board")
+        lock.acquire()
+        c._display_once(board, "board", False)
+        clock.t += 1.0
+        lock.release()
+        c._display_once(board, "board", False)
+        c.plugin_manager._warn_rate_limited.assert_not_called()
+        c.plugin_manager.health_tracker.record_busy_skip.assert_not_called()
+
+    def test_a_run_left_open_is_dropped_by_a_1hz_frame(self, held, clock):
+        c, lock = held
+        ticker = _plugin("ticker")
+        lock.acquire()
+        c._display_once(ticker, "ticker", False, report_hold=True)
+        lock.release()
+        c._display_once(ticker, "ticker", False)        # the 1 Hz loop draws
+        assert c._display_hold is None
+        clock.t += 5.0
+        c._display_once(ticker, "ticker", False, report_hold=True)
+        c.plugin_manager._warn_rate_limited.assert_not_called()

test/test_fetch_service.py

@@ -576,6 +576,42 @@ class TestCounters:
         assert snap["hosts"]["site.api.espn.com"]["requests"] == 1
         assert snap["totals"]["bytes"] == 3 * len(b'{"ok": 1}')
 
+    def test_wire_bytes_are_the_compressed_size(self, service):
+        # Built the way requests builds a real response: a urllib3
+        # HTTPResponse carrying a gzip body, decoded when .content is read.
+        import gzip
+        import io
+
+        from requests.adapters import HTTPAdapter
+        from urllib3.response import HTTPResponse
+
+        decoded = json.dumps({"events": [{"id": str(i), "name": "x" * 200}
+                                         for i in range(50)]}).encode()
+        wire = gzip.compress(decoded)
+
+        def handler(url, kwargs):
+            raw = HTTPResponse(body=io.BytesIO(wire), status=200,
+                               headers={"Content-Encoding": "gzip",
+                                        "Content-Type": "application/json"},
+                               preload_content=False, decode_content=True)
+            request = requests.Request("GET", url).prepare()
+            response = HTTPAdapter().build_response(request, raw)
+            response.content  # what Session.get does for a non-streamed call
+            return response
+
+        response = service.get(FakeSession(handler), "https://site.api.espn.com/x")
+        assert response.content == decoded
+        totals = _counters(service)
+        assert totals["bytes"] == len(decoded)
+        assert totals["wire_bytes"] == len(wire) < len(decoded)
+
+    def test_wire_bytes_fall_back_to_the_decoded_size(self, service):
+        # No urllib3 response behind it (a test double, another adapter):
+        # count what is known rather than nothing.
+        service.get(FakeSession(), "https://api.test/x")
+        totals = _counters(service)
+        assert totals["wire_bytes"] == totals["bytes"] == len(b'{"ok": 1}')
+
     def test_errors_and_http_errors(self, service):
         def handler(url, kwargs):
             if url.endswith("/down"):

test/test_on_demand_live_and_restore.py

@@ -21,18 +21,6 @@ SPORTS_MODES = ['nfl_live', 'nfl_recent', 'nfl_upcoming',
                 'ncaa_fb_live', 'ncaa_fb_recent', 'ncaa_fb_upcoming']
 
 
-def _last_write(cache_manager, key):
-    """The last ``cache_manager.set(key, ...)`` call.
-
-    Not simply the last ``set`` call: the controller's font-usage publisher
-    thread writes ``font_usage_snapshot`` to the same cache manager whenever
-    it wakes, so on a slow runner it can land after the write under test.
-    """
-    writes = [c for c in cache_manager.set.call_args_list if c.args and c.args[0] == key]
-    assert writes, f"nothing was written to {key!r}"
-    return writes[-1]
-
-
 def _sports_plugin(has_live_content=False):
     plugin = MagicMock(spec=['display', 'has_live_content', 'has_live_priority',
                              'get_live_modes'])
@@ -99,7 +87,10 @@ class TestANamedLiveModeIsShown:
     def test_the_named_mode_survives_a_restart(self, football):
         football._activate_on_demand({'plugin_id': 'football-scoreboard',
                                       'mode': 'ncaa_fb_live'})
-        saved = _last_write(football.cache_manager, 'display_on_demand_config')
+        # The last on-demand config write, not the last write of any key: the
+        # font-usage publisher thread writes its own key at its own pace.
+        saved = [c for c in football.cache_manager.set.call_args_list
+                 if c.args and c.args[0] == 'display_on_demand_config'][-1]
         config = saved.args[1]
         assert config['named_mode'] == 'ncaa_fb_live'
 
@@ -131,7 +122,10 @@ class TestARestoreWithNothingToResume:
     def test_it_is_reported_as_an_error(self, restored):
         assert restored.on_demand_status == 'error'
         assert restored.on_demand_last_error == 'restore-failed'
-        published = _last_write(restored.cache_manager, 'display_on_demand_state')
+        # The last on-demand state write, not the last write of any key: the
+        # font-usage publisher thread writes its own key at its own pace.
+        published = [c for c in restored.cache_manager.set.call_args_list
+                     if c.args and c.args[0] == 'display_on_demand_state'][-1]
         assert published.args[1]['status'] == 'error'
         assert published.args[1]['error'] == 'restore-failed'
 

test/web_interface/test_starlark_pixlet_routes.py

@@ -26,8 +26,15 @@ import pytest
 
 
 @pytest.fixture
-def client():
+def client(monkeypatch):
+    from web_interface import app as web_app
     from web_interface.app import app
+    # The captive-portal before_request hook shells out to systemctl/nmcli
+    # whenever its 30s cache is cold, so on a Linux host whether a request
+    # here runs subprocess depended on how long ago the previous one was --
+    # and several tests below stub subprocess. Pin it: no test in this file
+    # is about AP mode.
+    monkeypatch.setattr(web_app, 'is_ap_mode_active', lambda: False)
     app.config['TESTING'] = True
     with app.test_client() as c:
         yield c
@@ -1131,25 +1138,28 @@ class TestPixletEditorHostDefaultsButDoesNotOverride:
         class FakeProcess:
             pid = 424242
 
-        real_popen = mod.subprocess.Popen
-
         def fake_popen(cmd, *args, env=None, **kwargs):
-            # Only the editor launch is faked. Patching subprocess.Popen
-            # patches it for the whole request, and the captive-portal
-            # before_request hook runs `systemctl is-active hostapd` through
-            # subprocess.run whenever its 30s cache has expired -- which
-            # needs a real process (run() uses it as a context manager).
-            if str(script) not in cmd:
-                return real_popen(cmd, *args, env=env, **kwargs)
-            captured['env'] = env
+            if env is not None:
+                captured['env'] = env
             return FakeProcess()
 
+        # Swap the route module's own ``subprocess`` binding, not the shared
+        # ``subprocess.Popen``: patching the attribute on the real module is
+        # process-wide, and the app's before_request hook (the captive-portal
+        # check) runs ``subprocess.run`` -- ``with Popen(...)`` -- whenever its
+        # 30s AP-mode cache is cold on a host with systemctl. On the Linux CI
+        # runner that handed it this FakeProcess and 500'd the request, but
+        # only when the previous request was more than 30s earlier.
+        fake_subprocess = types.ModuleType('subprocess')
+        fake_subprocess.__dict__.update(mod.subprocess.__dict__)
+        fake_subprocess.Popen = fake_popen
+
         with patch.object(mod, '_validate_starlark_app_path',
                           return_value=(app_dir, None)), \
              patch.object(mod, '_PIXLET_EDITOR_SCRIPT', script), \
              patch.object(mod, '_PIXLET_EDITOR_STATE', state_file), \
              patch.object(mod, '_find_pixlet_binary', return_value='/usr/bin/pixlet'), \
-             patch.object(mod.subprocess, 'Popen', side_effect=fake_popen), \
+             patch.object(mod, 'subprocess', fake_subprocess), \
              patch.dict(os.environ):
             if operator_host is None:
                 os.environ.pop('PIXLET_EDITOR_HOST', None)