fix(logo): remember a missing logo instead of re-warning every rotation (#548)

* fix(logo): remember a missing logo instead of re-warning every rotation

load_logo() stat'd the path and logged a WARNING on every call, and the
positive cache never covered it because a miss returns None and caches
nothing. A file that is simply not there therefore produced one warning per
rotation for as long as the process ran -- measured on a live rig at 114 lines
in 24 hours for a single missing ticker icon, for a file nobody was going to
add.

Misses are now remembered for 10 minutes: warn once, then return None without
touching the disk. Bounded rather than permanent because logo_downloader
writes logos at runtime, so a file that appears later must still be picked up
without a restart. Downloads through load_logo_with_download() clear the entry
outright -- load_logo() consults the miss record before it stats the disk, so
without that a freshly downloaded logo would stay invisible for the whole
window.

This is in the core rather than in ledmatrix-stocks, where it was found, so
every plugin that goes through LogoHelper gets it.

_cache_order stays a list. Swapping the pair for an OrderedDict would shave an
O(n) scan per cache hit, but n is capped at cache_size (100 by default) and
test_logo_helper.py pins the current structure; not worth the churn.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014RRtqXDCnvnY6EQwhT5CV9

* fix(logo): make the miss TTL longer than the rotation it is meant to outlast

Deployed the previous commit to a live rig and measured it: no change at all.
"Logo not found for VOO" stayed at ~6 lines an hour, exactly the baseline.

The TTL was 600s and the display rotation is ~618s, so every recheck expired
just as the plugin came round again and the negative cache never once got to
suppress a warning. The fix was correct in shape and useless in practice,
which only measuring on the rig would show.

An hour instead. That is safe because the TTL is not the main way an entry
clears: load_logo_with_download() drops it the moment a download succeeds and
clear_cache() drops all of them. The TTL only covers a file that appeared some
other way -- someone copying one in by hand -- and waiting up to an hour for
that, or restarting, is a fair trade for not re-warning about a file nobody is
going to add.

The general lesson is in the comment: a TTL has to be long relative to the loop
that does the asking, not merely "a while".

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014RRtqXDCnvnY6EQwhT5CV9

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>

src/common/logo_helper.py

@@ -8,6 +8,7 @@ Extracted from LEDMatrix core to provide reusable functionality for plugins.
 import logging
 import os
 import tempfile
+import time
 from pathlib import Path
 from typing import Dict, List, Optional, Union
 
@@ -20,6 +21,21 @@ from src.common.permission_utils import (
     get_assets_file_mode
 )
 
+# How long a missing logo stays remembered as missing.
+#
+# This was 600s, and measured on a live rig that turned out to suppress nothing:
+# the display rotation is ~618s, so every recheck landed just as the plugin came
+# round again and the warning rate was unchanged at ~6/hour. A TTL has to be long
+# relative to the loop that does the asking, not merely "a while".
+#
+# An hour is safe because the TTL is not the main way an entry clears. A download
+# through load_logo_with_download() drops it immediately, and clear_cache() drops
+# all of them; the TTL only covers a file that appeared some other way -- someone
+# copying one in by hand. Waiting up to an hour for that, or restarting, is a fair
+# trade for not re-warning about a file nobody is going to add.
+MISSING_LOGO_RECHECK_SECONDS = 3600.0
+
+
 
 # Well above any real team logo; bounds what a remote URL can write to disk.
 MAX_LOGO_BYTES = 10 * 1024 * 1024
@@ -57,6 +73,14 @@ class LogoHelper:
         self._logo_cache: Dict[str, Image.Image] = {}
         self._cache_order: List[str] = []  # For LRU cache management
 
+        # Misses, so an absent file is stat'd and warned about once rather than
+        # on every call. Without this a permanently missing logo produced a
+        # warning per rotation forever -- measured at 114 lines in 24 hours for
+        # a single missing ticker icon, for a file nobody was going to add.
+        # Time-bounded rather than permanent so a logo that appears later (the
+        # downloader writes them at runtime) is still picked up.
+        self._missing_logos: Dict[str, float] = {}
+        
         # Session for HTTP requests
         self.session = requests.Session()
         self.session.headers.update({
@@ -100,9 +124,19 @@ class LogoHelper:
             self._cache_order.append(cache_key)
             return self._logo_cache[cache_key]
         
+        # A known-missing file: skip the stat and stay quiet until the entry
+        # ages out. Checked after the positive cache so a logo that has since
+        # been loaded always wins.
+        missed_at = self._missing_logos.get(cache_key)
+        if missed_at is not None:
+            if time.time() - missed_at < MISSING_LOGO_RECHECK_SECONDS:
+                return None
+            del self._missing_logos[cache_key]
+
         try:
             logo_path = Path(logo_path)
             if not logo_path.exists():
+                self._missing_logos[cache_key] = time.time()
                 self.logger.warning(f"Logo not found for {team_abbr} at {logo_path}")
                 return None
             
@@ -179,6 +213,11 @@ class LogoHelper:
             self._logo_cache.pop(key, None)
             if key in self._cache_order:
                 self._cache_order.remove(key)
+        # The file exists now, so any record of it being missing is wrong --
+        # and load_logo() consults that record before it stats the disk, so
+        # leaving it would hide a logo we just downloaded.
+        for key in [k for k in self._missing_logos if k.startswith(prefix)]:
+            del self._missing_logos[key]
 
     @staticmethod
     def _refresh_stale_placeholder(logo_path: Path) -> None:
@@ -270,6 +309,7 @@ class LogoHelper:
         """Clear the logo cache."""
         self._logo_cache.clear()
         self._cache_order.clear()
+        self._missing_logos.clear()
         self.logger.debug("Logo cache cleared")
     
     def get_cache_stats(self) -> Dict[str, int]:

test/test_logo_helper.py

@@ -24,7 +24,8 @@ import pytest
 import requests
 from PIL import Image, UnidentifiedImageError
 
-from src.common.logo_helper import MAX_LOGO_BYTES, LogoHelper
+from src.common.logo_helper import (MAX_LOGO_BYTES, MISSING_LOGO_RECHECK_SECONDS,
+                                    LogoHelper)
 
 
 @pytest.fixture(autouse=True)
@@ -494,3 +495,70 @@ class TestStalePlaceholderHandling:
             helper.load_logo_with_download("COLL", path, "http://x/c.png")
 
         assert should_attempt_download(path) is False
+
+
+class TestMissingLogosAreRememberedNotRewarned:
+    """A file that is not there does not become there by being asked again.
+
+    load_logo() stat'd the path and logged a WARNING on every call, so a
+    permanently absent logo produced one warning per rotation for as long as
+    the process ran -- measured at 114 lines in 24 hours for a single missing
+    ticker icon. The positive cache never covered this because a miss returns
+    None and caches nothing.
+    """
+
+    def test_a_missing_logo_warns_once(self, helper, tmp_path, caplog):
+        absent = tmp_path / "VOO.png"
+        with caplog.at_level(logging.WARNING):
+            for _ in range(50):
+                assert helper.load_logo("VOO", absent) is None
+        assert caplog.text.count("Logo not found for VOO") == 1, (
+            f"warned {caplog.text.count('Logo not found for VOO')} times in 50 calls")
+
+    def test_the_miss_is_not_remembered_forever(self, helper, tmp_path, monkeypatch):
+        """A logo written later -- logo_downloader does this at runtime -- must
+        still be picked up without a restart."""
+        path = tmp_path / "LATE.png"
+        assert helper.load_logo("LATE", path) is None
+
+        write_logo(path)
+        # Still inside the recheck window: the remembered miss stands.
+        assert helper.load_logo("LATE", path) is None
+
+        # Once it ages out, the next call stats the disk again and finds it.
+        for key in helper._missing_logos:
+            helper._missing_logos[key] -= MISSING_LOGO_RECHECK_SECONDS + 1
+        assert helper.load_logo("LATE", path) is not None
+
+    def test_a_download_clears_the_miss_immediately(self, helper, tmp_path):
+        """load_logo_with_download() must not be defeated by its own miss record.
+
+        load_logo() consults _missing_logos before it stats the disk, so a
+        logo we just downloaded would stay invisible for the whole recheck
+        window without the explicit invalidation.
+        """
+        path = tmp_path / "NEW.png"
+        assert helper.load_logo("NEW", path) is None
+        assert any(k.startswith("NEW_") for k in helper._missing_logos)
+
+        def _fake_download(url, file_path):
+            write_logo(Path(file_path))
+
+        with patch.object(helper, "_download_logo", side_effect=_fake_download):
+            got = helper.load_logo_with_download("NEW", path, logo_url="http://x/NEW.png")
+        assert got is not None, "a freshly downloaded logo was hidden by the miss record"
+        assert not any(k.startswith("NEW_") for k in helper._missing_logos)
+
+    def test_clear_cache_forgets_misses_too(self, helper, tmp_path):
+        helper.load_logo("GONE", tmp_path / "GONE.png")
+        assert helper._missing_logos
+        helper.clear_cache()
+        assert helper._missing_logos == {}
+
+    def test_a_present_logo_is_unaffected(self, helper, tmp_path, caplog):
+        path = write_logo(tmp_path / "OK.png")
+        with caplog.at_level(logging.WARNING):
+            for _ in range(10):
+                assert helper.load_logo("OK", path) is not None
+        assert "Logo not found" not in caplog.text
+        assert helper._missing_logos == {}