From 9772e3b189ccb8ed7d7916b2fb2808a5e3d9a614 Mon Sep 17 00:00:00 2001 From: Teknium <127238744+teknium1@users.noreply.github.com> Date: Sat, 1 Aug 2026 14:35:15 -0700 Subject: [PATCH] perf(model-picker): serve stale model caches instantly, refresh in background MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The remaining /model picker stall after the Copilot backoff fix: whenever the 1h provider-models disk cache TTL (or the remote model-catalog manifest TTL) lapsed mid-session, the next picker open blocked on 8-9 serial /v1/models round-trips (~2-3s measured) plus the catalog manifest fetch before rendering anything. Model catalogs change on release timescales, not hourly — so both caches now use stale-while-revalidate: - cached_provider_model_ids(): an expired entry whose credential fingerprint still matches is served immediately; a deduped daemon thread re-fetches the live catalog and rewrites the disk cache for the next open. Entries older than 7 days still block on a live fetch, credential rotation still busts the entry, and force_refresh still bypasses SWR. - model_catalog.get_catalog(): an expired disk manifest is served immediately with an off-thread refresh; only a truly cold cache (no disk copy) blocks on the network. Measured picker payload build with deliberately-expired caches: 2.9s -> 0.93s (first open in process) / 0.06s (subsequent opens). Combined with the Copilot fix (#76386): 7.3s -> ~0.06s for the common case. --- hermes_cli/model_catalog.py | 41 +++++ hermes_cli/models.py | 65 +++++++- tests/hermes_cli/test_model_cache_swr.py | 185 +++++++++++++++++++++++ 3 files changed, 289 insertions(+), 2 deletions(-) create mode 100644 tests/hermes_cli/test_model_cache_swr.py diff --git a/hermes_cli/model_catalog.py b/hermes_cli/model_catalog.py index fec73234aa45a..5aa479fa876b2 100644 --- a/hermes_cli/model_catalog.py +++ b/hermes_cli/model_catalog.py @@ -46,6 +46,7 @@ from __future__ import annotations import json import logging +import threading import time import urllib.error import urllib.request @@ -229,6 +230,36 @@ def _write_disk_cache(data: dict[str, Any]) -> None: logger.info("model catalog cache write failed: %s", exc) +# Stale-while-revalidate machinery: at most one background manifest refresh +# in flight per process. The refreshed manifest lands on disk; the NEXT +# get_catalog() call picks it up via the mtime check. +_catalog_swr_lock = threading.Lock() +_catalog_swr_inflight = False + + +def _spawn_catalog_swr_refresh(url: str) -> None: + """Refresh the catalog manifest off-thread (fire-and-forget, deduped).""" + global _catalog_swr_inflight + with _catalog_swr_lock: + if _catalog_swr_inflight: + return + _catalog_swr_inflight = True + + def _refresh() -> None: + global _catalog_swr_inflight + try: + fetched = _fetch_manifest_with_fallback(url, DEFAULT_FETCH_TIMEOUT) + if fetched is not None: + _write_disk_cache(fetched) + except Exception: + logger.debug("catalog SWR refresh failed", exc_info=True) + finally: + with _catalog_swr_lock: + _catalog_swr_inflight = False + + threading.Thread(target=_refresh, daemon=True, name="model-catalog-swr").start() + + # --------------------------------------------------------------------------- # Public API # --------------------------------------------------------------------------- @@ -268,6 +299,16 @@ def get_catalog(*, force_refresh: bool = False) -> dict[str, Any]: _catalog_cache_source_mtime = disk_mtime return disk_data + # Stale-while-revalidate: an expired disk copy is served immediately and + # refreshed off-thread, so interactive surfaces (the /model picker calls + # this via get_curated_nous_model_ids on every open) never block on the + # manifest fetch. Only a cold cache (no disk copy at all) still blocks. + if not force_refresh and disk_data is not None: + _catalog_cache = disk_data + _catalog_cache_source_mtime = disk_mtime + _spawn_catalog_swr_refresh(cfg["url"]) + return disk_data + # Need to (re)fetch. If it fails, fall back to any stale disk copy. fetched = _fetch_manifest_with_fallback(cfg["url"], DEFAULT_FETCH_TIMEOUT) if fetched is not None: diff --git a/hermes_cli/models.py b/hermes_cli/models.py index 5f1550e3ab9f3..0383f9ae5b90a 100644 --- a/hermes_cli/models.py +++ b/hermes_cli/models.py @@ -8,8 +8,10 @@ Add, remove, or reorder entries here — both `hermes setup` and from __future__ import annotations import json +import logging import os import re +import threading import urllib.parse import urllib.request import urllib.error @@ -21,6 +23,8 @@ from typing import Any, NamedTuple, Optional from hermes_cli import __version__ as _HERMES_VERSION from hermes_cli.urllib_security import open_credentialed_url +logger = logging.getLogger(__name__) + # Identify ourselves so endpoints fronted by Cloudflare's Browser Integrity # Check (error 1010) don't reject the default ``Python-urllib/*`` signature. _HERMES_USER_AGENT = f"hermes-cli/{_HERMES_VERSION}" @@ -3066,6 +3070,56 @@ def provider_model_ids(provider: Optional[str], *, force_refresh: bool = False) # to a live fetch — the picker keeps working. _PROVIDER_MODELS_CACHE_TTL = 3600 # 1h +# Stale-while-revalidate window: an expired-but-same-credentials entry is +# served IMMEDIATELY (picker opens stay instant) while a background daemon +# thread re-fetches the live catalog and rewrites the disk cache for the +# next open. Beyond this bound the entry is considered too old to trust and +# the caller blocks on a live fetch as before. Rationale: the /model picker's +# provider listing runs 8-9 serial /v1/models round-trips (~2-3s) whenever +# the 1h TTL lapses mid-session — model catalogs change on release timescales, +# not hourly, so serving hour-old data while refreshing off-thread is strictly +# better than stalling every picker surface (CLI, TUI, dashboard, gateway). +_PROVIDER_MODELS_STALE_SERVE_MAX = 7 * 24 * 3600 # 7d + +# Providers with a background SWR refresh currently in flight — dedupes +# concurrent refreshes so repeated picker opens during one refresh don't +# stack threads or duplicate network calls. +_swr_refresh_inflight: set = set() +_swr_refresh_lock = threading.Lock() + + +def _spawn_swr_refresh(provider: str) -> None: + """Kick a background refresh of *provider*'s model-id cache entry. + + Fire-and-forget daemon thread; at most one in flight per provider. + Failures are swallowed — the stale entry stays served until a later + refresh succeeds (same degradation the blocking path already had). + """ + with _swr_refresh_lock: + if provider in _swr_refresh_inflight: + return + _swr_refresh_inflight.add(provider) + + def _refresh() -> None: + try: + live = provider_model_ids(provider, force_refresh=True) + if live: + cache = _load_provider_models_cache() + cache[provider] = { + "fp": _credential_fingerprint(provider), + "at": time.time(), + "models": list(live), + } + _save_provider_models_cache(cache) + except Exception: + logger.debug("SWR refresh failed for %s", provider, exc_info=True) + finally: + with _swr_refresh_lock: + _swr_refresh_inflight.discard(provider) + + threading.Thread( + target=_refresh, daemon=True, name=f"model-cache-swr-{provider}" + ).start() def _provider_models_cache_path() -> Path: @@ -3205,9 +3259,16 @@ def cached_provider_model_ids( and entry.get("fp") == fp and isinstance(entry.get("models"), list) and entry["models"] - and (now - float(entry.get("at", 0))) < ttl_seconds ): - return list(entry["models"]) + age = now - float(entry.get("at", 0)) + if age < ttl_seconds: + return list(entry["models"]) + if age < _PROVIDER_MODELS_STALE_SERVE_MAX: + # Stale-while-revalidate: serve the expired entry immediately so + # interactive picker opens never block on serial /v1/models + # round-trips; refresh the cache off-thread for the next open. + _spawn_swr_refresh(normalized) + return list(entry["models"]) # Cache miss / stale / forced refresh — call the live path. live = provider_model_ids(normalized, force_refresh=force_refresh) diff --git a/tests/hermes_cli/test_model_cache_swr.py b/tests/hermes_cli/test_model_cache_swr.py new file mode 100644 index 0000000000000..e2eeaedbb3135 --- /dev/null +++ b/tests/hermes_cli/test_model_cache_swr.py @@ -0,0 +1,185 @@ +"""Stale-while-revalidate behavior for the model-id disk cache and the +remote model-catalog manifest. + +Regression tests for the /model picker stall: when the 1h provider-models +cache TTL (or the catalog manifest TTL) lapsed mid-session, the picker +blocked on 8-9 serial /v1/models round-trips (~2-3s) before rendering. +With SWR, an expired-but-credential-matching entry is served immediately +and refreshed off-thread for the next open. +""" + +from __future__ import annotations + +import time +from unittest.mock import patch + +import pytest + + +@pytest.fixture(autouse=True) +def _reset_swr_state(): + import hermes_cli.models as models_mod + with models_mod._swr_refresh_lock: + models_mod._swr_refresh_inflight.clear() + yield + with models_mod._swr_refresh_lock: + models_mod._swr_refresh_inflight.clear() + + +class TestProviderModelsSWR: + def _cache_entry(self, models, age_seconds, fp="fp"): + return {"fp": fp, "at": time.time() - age_seconds, "models": list(models)} + + def test_fresh_entry_served_without_refresh(self): + import hermes_cli.models as mod + + cache = {"openrouter": self._cache_entry(["m1"], age_seconds=10)} + with patch.object(mod, "_load_provider_models_cache", return_value=cache), \ + patch.object(mod, "_credential_fingerprint", return_value="fp"), \ + patch.object(mod, "_spawn_swr_refresh") as spawn, \ + patch.object(mod, "provider_model_ids") as live: + out = mod.cached_provider_model_ids("openrouter") + assert out == ["m1"] + spawn.assert_not_called() + live.assert_not_called() + + def test_stale_entry_served_immediately_with_background_refresh(self): + import hermes_cli.models as mod + + # 2h old — beyond the 1h TTL, within the 7d stale-serve window. + cache = {"openrouter": self._cache_entry(["m1", "m2"], age_seconds=7200)} + with patch.object(mod, "_load_provider_models_cache", return_value=cache), \ + patch.object(mod, "_credential_fingerprint", return_value="fp"), \ + patch.object(mod, "_spawn_swr_refresh") as spawn, \ + patch.object(mod, "provider_model_ids") as live: + out = mod.cached_provider_model_ids("openrouter") + assert out == ["m1", "m2"] # served stale, no blocking + spawn.assert_called_once_with("openrouter") + live.assert_not_called() # the caller thread never hit the network + + def test_too_old_entry_blocks_on_live_fetch(self): + import hermes_cli.models as mod + + age = mod._PROVIDER_MODELS_STALE_SERVE_MAX + 60 + cache = {"openrouter": self._cache_entry(["ancient"], age_seconds=age)} + with patch.object(mod, "_load_provider_models_cache", return_value=cache), \ + patch.object(mod, "_credential_fingerprint", return_value="fp"), \ + patch.object(mod, "_save_provider_models_cache"), \ + patch.object(mod, "_spawn_swr_refresh") as spawn, \ + patch.object(mod, "provider_model_ids", return_value=["fresh"]) as live: + out = mod.cached_provider_model_ids("openrouter") + assert out == ["fresh"] + spawn.assert_not_called() + live.assert_called_once() + + def test_credential_rotation_still_busts_stale_entry(self): + import hermes_cli.models as mod + + # Stale entry with a DIFFERENT fingerprint (key rotated) must NOT be + # served — it reflects the old credentials' catalog. + cache = {"openrouter": self._cache_entry(["old-key-models"], 7200, fp="old")} + with patch.object(mod, "_load_provider_models_cache", return_value=cache), \ + patch.object(mod, "_credential_fingerprint", return_value="new"), \ + patch.object(mod, "_save_provider_models_cache"), \ + patch.object(mod, "_spawn_swr_refresh") as spawn, \ + patch.object(mod, "provider_model_ids", return_value=["new-key-models"]): + out = mod.cached_provider_model_ids("openrouter") + assert out == ["new-key-models"] + spawn.assert_not_called() + + def test_force_refresh_bypasses_swr(self): + import hermes_cli.models as mod + + cache = {"openrouter": self._cache_entry(["m1"], age_seconds=7200)} + with patch.object(mod, "_load_provider_models_cache", return_value=cache), \ + patch.object(mod, "_credential_fingerprint", return_value="fp"), \ + patch.object(mod, "_save_provider_models_cache"), \ + patch.object(mod, "_spawn_swr_refresh") as spawn, \ + patch.object(mod, "provider_model_ids", return_value=["live"]) as live: + out = mod.cached_provider_model_ids("openrouter", force_refresh=True) + assert out == ["live"] + spawn.assert_not_called() + live.assert_called_once_with("openrouter", force_refresh=True) + + def test_swr_refresh_dedupes_inflight(self): + import hermes_cli.models as mod + + started = [] + + class FakeThread: + def __init__(self, target=None, daemon=None, name=None): + started.append(name) + self._target = target + + def start(self): + pass # never run — keeps the provider marked in-flight + + with patch.object(mod.threading, "Thread", FakeThread): + mod._spawn_swr_refresh("openrouter") + mod._spawn_swr_refresh("openrouter") # deduped + mod._spawn_swr_refresh("nous") + assert started == ["model-cache-swr-openrouter", "model-cache-swr-nous"] + + def test_swr_refresh_writes_cache_and_clears_inflight(self): + import hermes_cli.models as mod + + saved = {} + + def fake_save(data): + saved.update(data) + + captured = {} + + class InlineThread: + def __init__(self, target=None, daemon=None, name=None): + captured["target"] = target + + def start(self): + captured["target"]() # run synchronously + + with patch.object(mod.threading, "Thread", InlineThread), \ + patch.object(mod, "provider_model_ids", return_value=["fresh1", "fresh2"]), \ + patch.object(mod, "_credential_fingerprint", return_value="fp"), \ + patch.object(mod, "_load_provider_models_cache", return_value={}), \ + patch.object(mod, "_save_provider_models_cache", side_effect=fake_save): + mod._spawn_swr_refresh("openrouter") + + assert saved["openrouter"]["models"] == ["fresh1", "fresh2"] + assert "openrouter" not in mod._swr_refresh_inflight # cleared on completion + + +class TestCatalogSWR: + def test_stale_disk_catalog_served_with_background_refresh(self, tmp_path, monkeypatch): + import hermes_cli.model_catalog as mc + + manifest = {"version": 1, "providers": {"nous": {"models": [{"id": "hermes-4"}]}}} + monkeypatch.setattr(mc, "_catalog_cache", None) + monkeypatch.setattr(mc, "_catalog_cache_source_mtime", 0.0) + with patch.object(mc, "_load_catalog_config", return_value={ + "enabled": True, "ttl_hours": 1.0, "url": "https://example/cat.json", + "providers": {}}), \ + patch.object(mc, "_read_disk_cache", return_value=(manifest, time.time() - 7200)), \ + patch.object(mc, "_spawn_catalog_swr_refresh") as spawn, \ + patch.object(mc, "_fetch_manifest_with_fallback") as fetch: + out = mc.get_catalog() + assert out == manifest # stale copy served without blocking + spawn.assert_called_once() + fetch.assert_not_called() + + def test_cold_cache_still_blocks_on_fetch(self, monkeypatch): + import hermes_cli.model_catalog as mc + + manifest = {"version": 1, "providers": {}} + monkeypatch.setattr(mc, "_catalog_cache", None) + monkeypatch.setattr(mc, "_catalog_cache_source_mtime", 0.0) + with patch.object(mc, "_load_catalog_config", return_value={ + "enabled": True, "ttl_hours": 1.0, "url": "https://example/cat.json", + "providers": {}}), \ + patch.object(mc, "_read_disk_cache", return_value=(None, 0.0)), \ + patch.object(mc, "_spawn_catalog_swr_refresh") as spawn, \ + patch.object(mc, "_write_disk_cache"), \ + patch.object(mc, "_fetch_manifest_with_fallback", return_value=manifest) as fetch: + out = mc.get_catalog() + assert out == manifest + fetch.assert_called_once() + spawn.assert_not_called()