diff --git a/hermes_cli/copilot_auth.py b/hermes_cli/copilot_auth.py index 1b4ac33028fce..0f1ec8c03473d 100644 --- a/hermes_cli/copilot_auth.py +++ b/hermes_cli/copilot_auth.py @@ -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) diff --git a/tests/hermes_cli/test_copilot_token_exchange.py b/tests/hermes_cli/test_copilot_token_exchange.py index 5a9b7447b1b9b..3b448f30d5379 100644 --- a/tests/hermes_cli/test_copilot_token_exchange.py +++ b/tests/hermes_cli/test_copilot_token_exchange.py @@ -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