RomanNum3ral
/
hermes-agent
mirror of https://github.com/NousResearch/hermes-agent.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

fix(model-picker): stop Copilot token-exchange retry backoff from stalling /model open 

The no-args /model picker calls list_authenticated_providers(), which walks
every provider through load_pool(). For copilot, _seed_from_singletons()
re-runs the raw-token -> API-token exchange on every pass. When the exchange
is rejected (HTTP 403: token not Copilot-entitled, revoked, org-blocked),
the transient-network retry loop slept ~4.5s (1.5s + 3.0s backoff) before
degrading to the raw token — and nothing cached the failure, so EVERY picker
open, provider discovery pass, delegation spawn, and dashboard credential
listing paid the full 4.5s again.

Measured on a machine with a 403-rejected gh token: /model picker payload
build went from 7.3s to 1.0s cold and 0.06s warm.

Fixes:
- Permanent HTTP rejections (401/403/404) skip the retry backoff entirely —
  the loop exists for startup network races, not auth rejections.
- Negative cache keyed on token fingerprint: failed exchanges are not
  re-attempted for 30min (auth rejection) / 60s (transient network error).
- Success and evict_cached_exchanged_token() both clear the negative-cache
  entry, so the runtime stale-credential recovery path still forces a fresh
  exchange.
This commit is contained in:
Teknium 2026-08-01 13:10:03 -07:00
parent f88ed6c717
commit afdf8f9cc5
2 changed files with 140 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

51
hermes_cli/copilot_auth.py
View File

@ -310,6 +310,22 @@ _EXCHANGE_BACKOFF_BASE_SECONDS = 1.5 # sleeps ~1.5s, ~3.0s between attempts
_JWT_DISK_FILENAME = ".copilot_jwt.json"
_JWT_DISK_MAX_BYTES = 1_048_576 # 1 MiB cap on the persisted JWT store read
# Negative cache for failed exchanges. Without it, every load_pool("copilot")
# call re-runs the full exchange — and on a permanently-rejected token
# (HTTP 403: account not Copilot-entitled, expired grant, org policy) the
# retry backoff burned ~4.5s of time.sleep() on EVERY provider-discovery
# pass. The /model picker, delegation child spawns, and the web dashboard
# all walk that path, so a single bad Copilot token made all of them crawl.
# Maps raw-token fingerprint -> epoch until which exchange attempts are
# skipped (raise immediately). Success clears the entry.
_exchange_failure_cache: dict[str, float] = {}
_EXCHANGE_FAILURE_TTL_TRANSIENT_SECONDS = 60.0 # network blips: retry soon
_EXCHANGE_FAILURE_TTL_PERMANENT_SECONDS = 1800.0 # 401/403/404: won't heal
# HTTP statuses that indicate the token itself is rejected — retrying with
# backoff is pointless (the retry loop exists for startup network races,
# not for auth rejections) and sleeping on them just blocks the caller.
_EXCHANGE_PERMANENT_HTTP_STATUSES = frozenset({401, 403, 404})
def _token_fingerprint(raw_token: str) -> str:
"""Short fingerprint of a raw token for cache keying (avoids storing full token)."""
@ -352,6 +368,10 @@ def evict_cached_exchanged_token(raw_token: str) -> None:
return
fp = _token_fingerprint(raw_token)
_jwt_cache.pop(fp, None)
# Also clear any negative-cache entry: eviction is an explicit "force a
# fresh exchange" signal from the stale-credential recovery path, so the
# next exchange_copilot_token() must be allowed to hit the network.
_exchange_failure_cache.pop(fp, None)
path = _jwt_disk_path()
if not path or not path.exists():
return
@ -478,6 +498,17 @@ def exchange_copilot_token(raw_token: str, *, timeout: float = 10.0) -> tuple[st
_jwt_cache[fp] = (api_token, expires_at, base_url)
return api_token, expires_at, base_url
# Negative cache: a recent exchange failure for this token means the
# network round-trip (and its retry backoff) would just repeat. Fail
# fast so provider discovery / picker opens don't block on a token we
# already know is rejected or unreachable.
_fail_until = _exchange_failure_cache.get(fp, 0.0)
if time.time() < _fail_until:
raise ValueError(
"Copilot token exchange recently failed; skipping re-attempt "
f"for another {int(_fail_until - time.time())}s"
)
req = urllib.request.Request(
_TOKEN_EXCHANGE_URL,
method="GET",
@ -492,8 +523,13 @@ def exchange_copilot_token(raw_token: str, *, timeout: float = 10.0) -> tuple[st
# Retry with backoff. Startup network races (launchd relaunch, VPN/DHCP
# settling) make the first attempt flaky; without this the sole failure
# silently degrades to the raw token for the whole process lifetime.
# Permanent HTTP rejections (401/403/404 — token not Copilot-entitled,
# revoked, or org-blocked) skip the retry loop entirely: backoff exists
# for transient network races, and sleeping on an auth rejection just
# blocks the caller for ~4.5s with an identical outcome.
data = None
last_exc: Optional[Exception] = None
permanent_failure = False
for attempt in range(_EXCHANGE_MAX_ATTEMPTS):
try:
with urllib.request.urlopen(req, timeout=timeout) as resp:
@ -501,6 +537,14 @@ def exchange_copilot_token(raw_token: str, *, timeout: float = 10.0) -> tuple[st
break
except Exception as exc: # noqa: BLE001 — retry all, re-raise below
last_exc = exc
status = getattr(exc, "code", None) or getattr(exc, "status", None)
if status in _EXCHANGE_PERMANENT_HTTP_STATUSES:
permanent_failure = True
logger.debug(
"Copilot token exchange rejected (HTTP %s); not retrying",
status,
)
break
if attempt < _EXCHANGE_MAX_ATTEMPTS - 1:
sleep_s = _EXCHANGE_BACKOFF_BASE_SECONDS * (attempt + 1)
logger.debug(
@ -509,9 +553,16 @@ def exchange_copilot_token(raw_token: str, *, timeout: float = 10.0) -> tuple[st
)
time.sleep(sleep_s)
if data is None:
ttl = (
_EXCHANGE_FAILURE_TTL_PERMANENT_SECONDS
if permanent_failure
else _EXCHANGE_FAILURE_TTL_TRANSIENT_SECONDS
)
_exchange_failure_cache[fp] = time.time() + ttl
raise ValueError(
f"Copilot token exchange failed after {_EXCHANGE_MAX_ATTEMPTS} attempts: {last_exc}"
) from last_exc
_exchange_failure_cache.pop(fp, None)
api_token = data.get("token", "")
expires_at = data.get("expires_at", 0)

90
tests/hermes_cli/test_copilot_token_exchange.py
View File

@ -11,11 +11,13 @@ import pytest
@pytest.fixture(autouse=True)
def _clear_jwt_cache():
"""Reset the module-level JWT cache before each test."""
"""Reset the module-level JWT + failure caches before each test."""
import hermes_cli.copilot_auth as mod
mod._jwt_cache.clear()
mod._exchange_failure_cache.clear()
yield
mod._jwt_cache.clear()
mod._exchange_failure_cache.clear()
class TestExchangeCopilotToken:
@ -187,3 +189,89 @@ class TestJwtDiskStoreBounds:
store = _json.loads(path.read_text())
assert set(store) == {"fp1"}
assert store["fp1"]["api_token"] == "tid=fresh"
class TestExchangeFailureFastPath:
"""Auth rejections must not sleep, and failures must not repeat network hits.
Regression tests for the /model picker stall: a 403-rejected token made
every load_pool("copilot") burn ~4.5s in retry backoff, turning provider
discovery (picker open, delegation spawns, dashboard) into a 7s wait.
"""
def _http_error(self, code):
import urllib.error
return urllib.error.HTTPError(
url="https://api.github.com/copilot_internal/v2/token",
code=code, msg="err", hdrs=None, fp=None,
)
@patch("time.sleep")
@patch("urllib.request.urlopen")
def test_403_fails_fast_without_retry_or_sleep(self, mock_urlopen, mock_sleep):
from hermes_cli.copilot_auth import exchange_copilot_token
mock_urlopen.side_effect = self._http_error(403)
with pytest.raises(ValueError):
exchange_copilot_token("gho_rejected")
assert mock_urlopen.call_count == 1 # no retries on auth rejection
mock_sleep.assert_not_called()
@patch("time.sleep")
@patch("urllib.request.urlopen")
def test_negative_cache_skips_network_on_second_call(self, mock_urlopen, mock_sleep):
from hermes_cli.copilot_auth import exchange_copilot_token
mock_urlopen.side_effect = self._http_error(403)
with pytest.raises(ValueError):
exchange_copilot_token("gho_rejected")
with pytest.raises(ValueError, match="recently failed"):
exchange_copilot_token("gho_rejected")
assert mock_urlopen.call_count == 1 # second call never hit the network
@patch("time.sleep")
@patch("urllib.request.urlopen")
def test_transient_failure_still_retries_then_caches(self, mock_urlopen, mock_sleep):
import hermes_cli.copilot_auth as mod
from hermes_cli.copilot_auth import exchange_copilot_token, _token_fingerprint
mock_urlopen.side_effect = OSError("network unreachable")
with pytest.raises(ValueError):
exchange_copilot_token("gho_flaky")
assert mock_urlopen.call_count == mod._EXCHANGE_MAX_ATTEMPTS
fp = _token_fingerprint("gho_flaky")
until = mod._exchange_failure_cache.get(fp, 0)
# Transient TTL, not the 30-min permanent one.
assert 0 < until - time.time() <= mod._EXCHANGE_FAILURE_TTL_TRANSIENT_SECONDS + 1
@patch("time.sleep")
@patch("urllib.request.urlopen")
def test_success_clears_negative_cache(self, mock_urlopen, mock_sleep):
import hermes_cli.copilot_auth as mod
from hermes_cli.copilot_auth import exchange_copilot_token, _token_fingerprint
fp = _token_fingerprint("gho_recovering")
# Simulate an expired negative-cache entry so the call proceeds.
mod._exchange_failure_cache[fp] = time.time() - 1
resp_data = json.dumps(
{"token": "tid=ok;exp=1", "expires_at": time.time() + 1800}
).encode()
mock_resp = MagicMock()
mock_resp.read.return_value = resp_data
mock_resp.__enter__ = MagicMock(return_value=mock_resp)
mock_resp.__exit__ = MagicMock(return_value=False)
mock_urlopen.return_value = mock_resp
api_token, _, _ = exchange_copilot_token("gho_recovering")
assert api_token == "tid=ok;exp=1"
assert fp not in mod._exchange_failure_cache
def test_evict_clears_negative_cache(self):
import hermes_cli.copilot_auth as mod
from hermes_cli.copilot_auth import evict_cached_exchanged_token, _token_fingerprint
fp = _token_fingerprint("gho_stale")
mod._exchange_failure_cache[fp] = time.time() + 999
evict_cached_exchanged_token("gho_stale")
assert fp not in mod._exchange_failure_cache