Skip to content

fix(auth): downgrade expected transient states from warn to debug - #11937

Merged
diegosouzapw merged 1 commit into
diegosouzapw:release/v3.8.51from
patrykkopycinski:fix/auth-log-warn-to-debug
Aug 30, 2026
Merged

diegosouzapw merged 1 commit into
diegosouzapw:release/v3.8.51from
patrykkopycinski:fix/auth-log-warn-to-debug

Conversation

@patrykkopycinski

Copy link
Copy Markdown
Contributor

Problem

Two log.warn() calls in src/sse/services/auth.ts fire for normal, recoverable operational states:

Message Condition
${provider} | N accounts found but none active All connections are rate-limited; the caller receives allRateLimited: true with a retryAfter value and handles it.
No credentials for ${provider} No active account was found; upstream combo routing or the circuit breaker handles this.

Both conditions are expected during normal operation with many provider connections and produce log noise at the warn level (visible by default), especially when rate limits are cycling.

Fix

Downgrade both calls to log.debug():

// before
log.warn("AUTH", `${provider} | ${allConnections.length} accounts found but none active`);
log.warn("AUTH", `No credentials for ${provider}`);

// after
log.debug("AUTH", `${provider} | ${allConnections.length} accounts found but none active`);
log.debug("AUTH", `No credentials for ${provider}`);

debug is the correct level: the surrounding code already handles both cases gracefully and the caller has full context. No information is lost — operators who need to diagnose auth flow can set APP_LOG_LEVEL=debug.

Two log.warn() calls in auth.ts fired for normal operational states:
- "accounts found but none active": all connections rate-limited; the
  caller already handles this via allRateLimited/retryAfter return value.
- "No credentials for <provider>": no active account was found; this is
  expected when all accounts are in cooldown and is handled upstream.

These are recoverable, transient conditions that produce log noise when
running with many provider connections. debug is the correct level since
the surrounding code already handles both cases gracefully.
@diegosouzapw
diegosouzapw merged commit ff07430 into diegosouzapw:release/v3.8.51 Aug 30, 2026
3 checks passed
diegosouzapw added a commit that referenced this pull request Sep 16, 2026
#13879)

#13832. A user reported that `nvidia` and `openrouter` — added after the
initial setup — always failed chat with `No active credentials for provider: X`,
while on the same instance and the same minute `/api/providers/{id}/test`
returned valid and `/sync-models` pulled 82 models.

Reproducing the resolution chain on the tip shows no defect in it: a connection
created exactly as `POST /api/providers` creates one resolves for every model
tried, and creation order is irrelevant — the query is `provider = ? AND
is_active = 1`, there is no boot-time registry and no migration that backfills
only older rows.

The three-line AUTH log the reporter pasted is reachable from exactly one place:
the pool arriving EMPTY at the key-policy filter. Every post-query skip produces
a different message ("all N accounts unavailable"). So the connections exist and
are active; the calling key's `allowed_connections` / quota scope removed them —
the shape you get from a key minted before those providers existed, which is
also why the older providers on that key keep working.

The real defect is that nothing ever said so. `/test` and `/sync-models` address
a connection by id and never consult the key's scope, so they cannot contradict
it, and the one log line that hinted at the filter became `debug` in #11937.

`getProviderCredentials` now counts the connections it had before applying the
key policy and, when that filter is what emptied the pool, returns
`{ blockedByKeyPolicy, blockedCount }` instead of a bare null. `handleNoCredentials`
turns it into a 403 naming the allowlist and the fix, alongside the existing
allRateLimited/allExpired branches. 403, not 401: the credential is valid, this
principal just may not use it.

Test is red-first in tests/unit/chat-helpers.test.ts (it asserts the status, the
count and that the message names the gate).

This does not close the report on its own — it makes the next occurrence
self-explanatory. The reporter still needs to confirm their key's
allowed_connections/allowed_quotas.
muhamadgalihsaputra pushed a commit to niyatna/NiyatnaRoute that referenced this pull request Sep 27, 2026
…egosouzapw#11937)

Boarded with 8 other PRs in one combined worktree: typecheck:core, check:file-size, check:changelog-integrity, check:complexity, check:cognitive-complexity, check:cycles, check-native-deps all green; 75/75 focused tests pass. Trivial, correct log-level fix — both conditions are already handled gracefully by callers. Thanks.
muhamadgalihsaputra pushed a commit to niyatna/NiyatnaRoute that referenced this pull request Sep 27, 2026
diegosouzapw#13879)

diegosouzapw#13832. A user reported that `nvidia` and `openrouter` — added after the
initial setup — always failed chat with `No active credentials for provider: X`,
while on the same instance and the same minute `/api/providers/{id}/test`
returned valid and `/sync-models` pulled 82 models.

Reproducing the resolution chain on the tip shows no defect in it: a connection
created exactly as `POST /api/providers` creates one resolves for every model
tried, and creation order is irrelevant — the query is `provider = ? AND
is_active = 1`, there is no boot-time registry and no migration that backfills
only older rows.

The three-line AUTH log the reporter pasted is reachable from exactly one place:
the pool arriving EMPTY at the key-policy filter. Every post-query skip produces
a different message ("all N accounts unavailable"). So the connections exist and
are active; the calling key's `allowed_connections` / quota scope removed them —
the shape you get from a key minted before those providers existed, which is
also why the older providers on that key keep working.

The real defect is that nothing ever said so. `/test` and `/sync-models` address
a connection by id and never consult the key's scope, so they cannot contradict
it, and the one log line that hinted at the filter became `debug` in diegosouzapw#11937.

`getProviderCredentials` now counts the connections it had before applying the
key policy and, when that filter is what emptied the pool, returns
`{ blockedByKeyPolicy, blockedCount }` instead of a bare null. `handleNoCredentials`
turns it into a 403 naming the allowlist and the fix, alongside the existing
allRateLimited/allExpired branches. 403, not 401: the credential is valid, this
principal just may not use it.

Test is red-first in tests/unit/chat-helpers.test.ts (it asserts the status, the
count and that the message names the gate).

This does not close the report on its own — it makes the next occurrence
self-explanatory. The reporter still needs to confirm their key's
allowed_connections/allowed_quotas.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants