diff --git a/src/__tests__/baselines/source-function-lines.json b/src/__tests__/baselines/source-function-lines.json index c97a01137..4aa083037 100644 --- a/src/__tests__/baselines/source-function-lines.json +++ b/src/__tests__/baselines/source-function-lines.json @@ -1,7 +1,7 @@ { "$comment": "Production functions over 200 lines, keyed \"file :: name\", and their length. Maintained by src/__tests__/source-size-ratchet.test.ts.", "count": 352, - "total": 113949, + "total": 113900, "entries": { "app/achievements/page.tsx :: AchievementsPage": 206, "app/api/admin/backups/upload/route.ts :: apiHandler(arg)": 314, @@ -255,8 +255,8 @@ "lib/ai/coach/turn/pipeline.ts :: runTurn": 274, "lib/ai/coach/turn/reply-guards.ts :: guardReply": 331, "lib/ai/codex-client.ts :: parseResponse": 302, - "lib/ai/local-client.ts :: generateCompletionStream": 298, - "lib/ai/openai-client.ts :: generateCompletion": 375, + "lib/ai/local-client.ts :: generateCompletionStream": 294, + "lib/ai/openai-client.ts :: generateCompletion": 335, "lib/analytics/bp-in-target-fast-path.ts :: computeFromRollups": 203, "lib/analytics/compliance/display.ts :: calculateCompliance": 212, "lib/analytics/correlations-fast-path.ts :: computeCorrelationHypothesesFastPath": 256, @@ -299,7 +299,7 @@ "lib/insights/comprehensive-generate.ts :: generateComprehensiveInsight": 876, "lib/insights/features.ts :: extractFeatures": 796, "lib/insights/mood-aggregates.ts :: fetchMoodAggregates": 246, - "lib/insights/status-provider.ts :: runStatusCompletion": 241, + "lib/insights/status-provider.ts :: runStatusCompletion": 236, "lib/integrations/connection-health-load.ts :: loadConnectionFacts": 227, "lib/integrations/status.ts :: recordSyncFailure": 292, "lib/jobs/apple-health-import-worker.ts :: handleAppleHealthImport": 300, diff --git a/src/__tests__/baselines/version-stamp-comments.json b/src/__tests__/baselines/version-stamp-comments.json index 91b14f0e0..e3c126303 100644 --- a/src/__tests__/baselines/version-stamp-comments.json +++ b/src/__tests__/baselines/version-stamp-comments.json @@ -1,7 +1,7 @@ { "$comment": "Comment lines that open with a release version, per file under src/. Maintained by src/__tests__/version-stamp-ratchet.test.ts.", "count": 2897, - "total": 9273, + "total": 9272, "entries": { "__tests__/account-payload-consumer-guard.test.ts": 2, "__tests__/acting-account-boundary-guard.test.ts": 7, @@ -1751,7 +1751,7 @@ "lib/ai/local-client.ts": 18, "lib/ai/medical-references.ts": 1, "lib/ai/mock-client.ts": 5, - "lib/ai/openai-client.ts": 17, + "lib/ai/openai-client.ts": 16, "lib/ai/prompts/__tests__/assessment-prompt-contract.test.ts": 5, "lib/ai/prompts/__tests__/briefing-personalisation.test.ts": 1, "lib/ai/prompts/__tests__/coach-prompt-locale.test.ts": 1, diff --git a/src/lib/ai/__tests__/provider-runner-background-bench.test.ts b/src/lib/ai/__tests__/provider-runner-background-bench.test.ts new file mode 100644 index 000000000..18b29e814 --- /dev/null +++ b/src/lib/ai/__tests__/provider-runner-background-bench.test.ts @@ -0,0 +1,207 @@ +/** + * #1279 — background work and a provider the health ledger has benched. + * + * A chain whose only entry answered every call with reasoning and no answer + * was called by every background job: the ledger counted the failures and + * paused the provider, but a paused provider only moved to the tail of the + * chain, and the tail is still walked. A job now leaves a benched provider + * out (the local floor only once it is paused), says so once per window, and + * a person's own call still reaches it and reports its error. + */ +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; + +const emitSignal = vi.hoisted(() => vi.fn()); +vi.mock("@/lib/logging/signal", () => ({ + emitSignal: (...a: unknown[]) => emitSignal(...a), +})); + +import { + singleUserTurn, + type AIProvider, + type CompletionParams, + type CompletionResult, +} from "../types"; +import { + AllProvidersFailedError, + clearLastWorkingProviderCache, + runRawCompletionWithFallback, +} from "../provider-runner"; +import { + HARD_FAILURE_SKIP_THRESHOLD, + PROVIDER_PAUSE_THRESHOLD, + createInMemoryProviderHealthLedger, +} from "../provider-health-ledger"; +import type { ProviderChainType } from "../provider-chain"; + +/** Answers every call with reasoning and no answer, as the clients report it. */ +class AnswerlessProvider implements AIProvider { + readonly type: AIProvider["type"]; + calls = 0; + constructor(type: AIProvider["type"] = "openai-compatible") { + this.type = type; + } + async generateCompletion(_: CompletionParams): Promise { + this.calls += 1; + throw Object.assign(new Error("returned empty content"), { + httpStatus: 0, + kind: "reasoning_only", + tokensUsed: 2700, + }); + } +} + +function walk( + surface: "job" | "coach", + userId: string, + providerType: ProviderChainType, + instance: AIProvider, + ledger: ReturnType, +) { + return runRawCompletionWithFallback({ + userId, + surface, + providers: [{ providerType, instance }], + params: singleUserTurn({ system: "s", user: "u" }), + ledger, + }); +} + +function signals(action: string) { + return emitSignal.mock.calls + .map((c) => c[0] as { action: string; meta: Record }) + .filter((s) => s.action === action); +} + +beforeEach(() => { + clearLastWorkingProviderCache(); + emitSignal.mockClear(); +}); + +afterEach(() => { + vi.useRealTimers(); +}); + +describe("#1279: background work and a benched provider", () => { + it("stops calling the only provider once the ledger benches it, for jobs", async () => { + const ledger = createInMemoryProviderHealthLedger(); + const gateway = new AnswerlessProvider(); + for (let i = 0; i < HARD_FAILURE_SKIP_THRESHOLD; i += 1) { + await expect( + walk("job", "u-bench", "openai-compatible", gateway, ledger), + ).rejects.toBeInstanceOf(AllProvidersFailedError); + } + expect(gateway.calls).toBe(HARD_FAILURE_SKIP_THRESHOLD); + + // Ten more jobs inside the window: none of them sends a request. + for (let i = 0; i < 10; i += 1) { + const err = await walk( + "job", + "u-bench", + "openai-compatible", + gateway, + ledger, + ).catch((e) => e); + expect(err).toBeInstanceOf(AllProvidersFailedError); + expect((err as AllProvidersFailedError).attempts).toEqual([ + expect.objectContaining({ + providerType: "openai-compatible", + failureKind: "paused", + httpStatus: null, + }), + ]); + } + expect(gateway.calls).toBe(HARD_FAILURE_SKIP_THRESHOLD); + // One line for the window, not one per job. + expect(signals("ai.chain.background_paused")).toHaveLength(1); + expect(signals("ai.chain.background_paused")[0].meta).toMatchObject({ + provider: "openai-compatible", + reason: "backoff", + }); + }); + + it("still sends a person's own call to the benched provider and reports its error", async () => { + const ledger = createInMemoryProviderHealthLedger(); + const gateway = new AnswerlessProvider(); + for (let i = 0; i < PROVIDER_PAUSE_THRESHOLD; i += 1) { + await walk("job", "u-coach", "openai-compatible", gateway, ledger).catch( + () => undefined, + ); + } + const before = gateway.calls; + const err = await walk( + "coach", + "u-coach", + "openai-compatible", + gateway, + ledger, + ).catch((e) => e); + expect(gateway.calls).toBe(before + 1); + expect((err as AllProvidersFailedError).attempts[0].failureKind).toBe( + "reasoning_only", + ); + }); + + it("logs once more when a new window opens", async () => { + vi.useFakeTimers(); + const ledger = createInMemoryProviderHealthLedger(); + const gateway = new AnswerlessProvider(); + for (let i = 0; i < HARD_FAILURE_SKIP_THRESHOLD; i += 1) { + await walk("job", "u-window", "openai-compatible", gateway, ledger).catch( + () => undefined, + ); + } + await walk("job", "u-window", "openai-compatible", gateway, ledger).catch( + () => undefined, + ); + // The five-minute backoff lifts; the next job tries, fails, re-arms. + vi.advanceTimersByTime(6 * 60 * 1000); + await walk("job", "u-window", "openai-compatible", gateway, ledger).catch( + () => undefined, + ); + await walk("job", "u-window", "openai-compatible", gateway, ledger).catch( + () => undefined, + ); + expect(gateway.calls).toBe(HARD_FAILURE_SKIP_THRESHOLD + 1); + expect(signals("ai.chain.background_paused")).toHaveLength(2); + }); + + it("keeps the local floor through a short backoff and leaves it out once paused", async () => { + const ledger = createInMemoryProviderHealthLedger(); + const local = new AnswerlessProvider("local"); + for (let i = 0; i < HARD_FAILURE_SKIP_THRESHOLD; i += 1) { + await walk("job", "u-local", "local", local, ledger).catch( + () => undefined, + ); + } + // Backoff: the floor is still called. + await walk("job", "u-local", "local", local, ledger).catch(() => undefined); + expect(local.calls).toBe(HARD_FAILURE_SKIP_THRESHOLD + 1); + while (local.calls < PROVIDER_PAUSE_THRESHOLD) { + await walk("job", "u-local", "local", local, ledger).catch( + () => undefined, + ); + } + // Paused: background work leaves it alone. + await walk("job", "u-local", "local", local, ledger).catch(() => undefined); + await walk("job", "u-local", "local", local, ledger).catch(() => undefined); + expect(local.calls).toBe(PROVIDER_PAUSE_THRESHOLD); + }); + + it("sums what the failed hops reported spending", async () => { + const ledger = createInMemoryProviderHealthLedger(); + const err = await runRawCompletionWithFallback({ + userId: "u-spend", + surface: "job", + providers: [ + { + providerType: "openai-compatible", + instance: new AnswerlessProvider(), + }, + { providerType: "local", instance: new AnswerlessProvider("local") }, + ], + params: singleUserTurn({ system: "s", user: "u" }), + ledger, + }).catch((e) => e); + expect((err as AllProvidersFailedError).tokensSpent).toBe(5400); + }); +}); diff --git a/src/lib/ai/background-bench.ts b/src/lib/ai/background-bench.ts new file mode 100644 index 000000000..0a5fb5614 --- /dev/null +++ b/src/lib/ai/background-bench.ts @@ -0,0 +1,84 @@ +/** + * #1279 — background work and a provider the health ledger has benched. + * + * An interactive walk keeps a benched provider at the tail of the chain, so a + * person never loses their only provider to a cooldown. Background work has + * nobody waiting and no reason to call a provider that just failed several + * times in a row: a chain whose only entry answered every call with reasoning + * and no answer was called by every background job, all day, because the tail + * is still walked. So a job leaves every benched provider out until its + * window lifts, and the window grows while the failures continue + * (`hardFailureCooldownMs` in `provider-health-ledger.ts`). The ledger is + * durable, so the bench holds across workers and restarts. + * + * The local floor is left out only once it is paused, past a brief backoff: + * it costs no money, but a model that never answers still occupies the + * machine it runs on. + */ +import { emitSignal } from "@/lib/logging/signal"; +import type { ProviderChainType } from "./provider-chain"; +import type { ProviderSkipHint } from "./provider-health-ledger"; + +export interface BenchedProvider { + candidate: C; + hint: ProviderSkipHint; +} + +/** + * Split a chain into what background work walks and what it leaves out. + * `isFloor` names the providers that are never benched for a person (the + * local model). + */ +export function partitionForBackgroundWork< + C extends { providerType: ProviderChainType }, +>( + providers: readonly C[], + skips: ReadonlyMap, + isFloor: (type: ProviderChainType) => boolean, +): { walkable: C[]; benched: Array> } { + const walkable: C[] = []; + const benched: Array> = []; + for (const candidate of providers) { + const hint = skips.get(candidate.providerType); + const leftOut = + hint !== undefined && + (!isFloor(candidate.providerType) || hint.reason === "paused"); + if (leftOut) benched.push({ candidate, hint }); + else walkable.push(candidate); + } + return { walkable, benched }; +} + +/** + * One `ai.chain.background_paused` line per bench window, per process: the + * first background job that finds the provider benched says so, the rest + * mark it on their own event only. Keyed by user and provider, holding the + * window's end, so a new window logs once more. + */ +const LOGGED_SLOT = Symbol.for("healthlog.ai.backgroundBenchLogged"); +const logged: Map = ((globalThis as Record)[ + LOGGED_SLOT +] ??= new Map()) as Map; + +export function signalBackgroundBench( + userId: string, + providerType: ProviderChainType, + hint: ProviderSkipHint, +): void { + const key = `${userId}\u0000${providerType}`; + const until = hint.retryAt?.getTime() ?? 0; + if (logged.get(key) === until) return; + logged.set(key, until); + emitSignal({ + action: "ai.chain.background_paused", + level: "warn", + meta: { + provider: providerType, + reason: hint.reason, + retry_in_minutes: + until > 0 + ? Math.max(0, Math.ceil((until - Date.now()) / 60_000)) + : null, + }, + }); +} diff --git a/src/lib/ai/failure-kind.ts b/src/lib/ai/failure-kind.ts index 421a5da0a..88e9685fd 100644 --- a/src/lib/ai/failure-kind.ts +++ b/src/lib/ai/failure-kind.ts @@ -40,6 +40,11 @@ export type ProviderFailureKind = | "embedded_error" /** A non-2xx HTTP status. */ | "http" + /** + * #1279 — not sent: background work waits out a provider the health + * ledger has benched after failures in a row (`provider-runner.ts`). + */ + | "paused" /** A transport failure with no code this list knows. */ | "network" | "unknown"; diff --git a/src/lib/ai/local-client.ts b/src/lib/ai/local-client.ts index c10b7c623..1371aaac0 100644 --- a/src/lib/ai/local-client.ts +++ b/src/lib/ai/local-client.ts @@ -25,7 +25,6 @@ import { type JsonModeDialect, } from "./json-dialect"; import type { ReasoningEffort } from "./reasoning-effort"; -import { emitSignal } from "@/lib/logging/signal"; import { ANSWERS_ONLY_UNREASONED, annotateReasoningDowngrade, @@ -35,7 +34,7 @@ import { } from "./reasoning/dialect-cache"; import { uncontrolledThinkingRoom } from "./reasoning/levels"; import { - nextAnswerlessStep, + askAgainUnreasoned, reasonsUnasked, withEarlierSpend, } from "./reasoning/answerless"; @@ -123,8 +122,7 @@ function emptyReplyError(hadReasoning: boolean, spent: number | null): Error { httpStatus: 0, kind: hadReasoning ? "reasoning_only" : "empty_response", upstream: "local", - // #1279 — what the reply cost, so the day's ledger charges it instead of - // refunding a call that was paid for. + // #1279 — what the reply cost, for the day's ledger to charge. ...(spent !== null ? { tokensUsed: spent } : {}), }); return err; @@ -305,48 +303,32 @@ export class LocalOpenAICompatibleClient implements AIProvider { * "none"` answers in `content`. So when a request that did not already say * `none` comes back empty with reasoning (or after asking to reason), learn * that this endpoint and model answer only unreasoned, and tell the caller - * to ask once more. Returns false when the empty reply is final. - * - * #1279 — once per call, and a model whose `none` reply was answerless too - * is not asked with `none` again while the lesson holds - * (`reasoning/answerless.ts`). + * to ask once more (#1279: at most once, and never again for a model whose + * `none` reply was answerless too). False when the empty reply is final. */ private learnAnswerlessReasoning( params: CompletionParams, hadReasoning: boolean, finishReason: string | undefined, ): boolean { - const sent = this.sentReasoningEffort(params); - const finish = - finishReason === "length" || finishReason === "stop" - ? finishReason - : "other"; - const step = nextAnswerlessStep( - this.reasoningDialectKey(), - sent, + return askAgainUnreasoned({ + key: this.reasoningDialectKey(), + provider: "local", + signals: "ai.local", + sent: this.sentReasoningEffort(params), hadReasoning, - ); - if (step.kind === "final") { - if (step.learnedRegardless) { - emitSignal({ - action: "ai.local.reasoning_unswitchable", - level: "warn", - meta: { finish }, - }); - } - return false; - } - annotateReasoningDowngrade("local", sent ?? "default", "none"); - emitSignal({ - action: "ai.local.reasoning_answerless", - level: "warn", - meta: { - effort: sent ?? "default", - finish, - reasoning: hadReasoning, - }, + finishReason, }); - return true; + } + + /** #1279 — the streamed call once more, carrying this reply's spend. */ + private streamAgain( + params: CompletionParams, + onDelta: (delta: string) => void, + spent: number | null, + ): Promise { + const again = this.generateCompletionStream(params, onDelta); + return withEarlierSpend(again, spent); } async generateCompletion( @@ -620,17 +602,9 @@ export class LocalOpenAICompatibleClient implements AIProvider { ); if (!content) { const spent = json?.usage?.total_tokens ?? null; - if ( - this.learnAnswerlessReasoning( - params, - hadReasoning, - json?.choices?.[0]?.finish_reason, - ) - ) { - return withEarlierSpend( - this.generateCompletionStream(params, onDelta), - spent, - ); + const finish = json?.choices?.[0]?.finish_reason; + if (this.learnAnswerlessReasoning(params, hadReasoning, finish)) { + return this.streamAgain(params, onDelta, spent); } collector.result(null); throw emptyReplyError(hadReasoning, spent); @@ -830,10 +804,7 @@ export class LocalOpenAICompatibleClient implements AIProvider { const hadReasoning = streamedReasoning || endState === "inside" || tail.took; if (this.learnAnswerlessReasoning(params, hadReasoning, finishReason)) { - return withEarlierSpend( - this.generateCompletionStream(params, onDelta), - tokensUsed, - ); + return this.streamAgain(params, onDelta, tokensUsed); } collector.result(reasoningTokens); throw emptyReplyError(hadReasoning, tokensUsed); diff --git a/src/lib/ai/openai-client.ts b/src/lib/ai/openai-client.ts index 5b515406b..8380153a7 100644 --- a/src/lib/ai/openai-client.ts +++ b/src/lib/ai/openai-client.ts @@ -21,7 +21,7 @@ import { rememberReasoningDialect, } from "./reasoning/dialect-cache"; import { - nextAnswerlessStep, + askAgainUnreasoned, reasonsUnasked, withEarlierSpend, } from "./reasoning/answerless"; @@ -439,64 +439,13 @@ export class OpenAIClient implements AIProvider { // A reply with tool calls and no prose is valid (F1 tool loop); only an // empty reply with neither content NOR tool calls is an error. if (!content && !toolCalls) { - // #1267 — a gateway in front of a thinking model (Ollama serving - // Gemma 4, say) can answer with the thought in `reasoning` and no - // content. Asked with `none`, the same model answers; learn that once - // and ask again. #1279 — once, and never `none` again for a model the - // repeat showed ignores it. Same rule as the Local client. - const sentEffort = - reasoningWire.kind !== "none" ? reasoningWire.effort : entryEffort; - const hadReasoning = reply.hadReasoning; - const spent = json.usage?.total_tokens ?? null; - const finish = - choice?.finish_reason === "length" || choice?.finish_reason === "stop" - ? choice.finish_reason - : "other"; - const step = this.isGateway - ? nextAnswerlessStep( - this.reasoningDialectKey(), - sentEffort, - hadReasoning, - ) - : null; - if (step?.kind === "ask_unreasoned") { - annotateReasoningDowngrade(this.type, sentEffort ?? "default", "none"); - emitSignal({ - action: "ai.gateway.reasoning_answerless", - level: "warn", - meta: { - effort: sentEffort ?? "default", - finish, - reasoning: hadReasoning, - }, - }); - return withEarlierSpend(this.generateCompletion(params), spent); - } - if (step?.kind === "final" && step.learnedRegardless) { - emitSignal({ - action: "ai.gateway.reasoning_unswitchable", - level: "warn", - meta: { finish }, - }); - } - // v1.20.1 — tag the empty-reply throw with a sentinel `httpStatus: 0` + - // `kind` so the provider-chain classifier can tell an empty 200-OK reply - // apart from a genuine transport failure (ECONNRESET, DNS, timeout) in - // observability. The cascade is unchanged: `isHardProviderFailure` - // already treats `status <= 0` as a hard failure and walks to the next - // provider. - const err = new Error( - `${this.isGateway ? "OpenAI-compatible gateway" : "OpenAI"} returned empty content`, - ); - Object.assign(err, { - httpStatus: 0, - kind: hadReasoning ? "reasoning_only" : "empty_response", - upstream: this.isGateway ? "openai-compatible" : "openai", - // #1279 — what the reply cost upstream, so the day's ledger charges - // it instead of refunding a call that was paid for. - ...(spent !== null ? { tokensUsed: spent } : {}), + return this.answerless(params, { + sent: + reasoningWire.kind !== "none" ? reasoningWire.effort : entryEffort, + hadReasoning: reply.hadReasoning, + finishReason: choice?.finish_reason, + spent: json.usage?.total_tokens ?? null, }); - throw err; } const summary = reply.reasoning ? [reply.reasoning.trim()] : []; @@ -554,6 +503,54 @@ export class OpenAIClient implements AIProvider { }; } + /** + * A reply with neither an answer nor tool calls. #1267 — a gateway in front + * of a thinking model (Ollama serving Gemma 4, say) can answer with the + * thought in `reasoning` and no content; asked with `none`, the same model + * answers, so that is learned once and the call asked again. #1279 — once, + * and never `none` again for a model the repeat showed ignores it. Same + * rule as the Local client (`reasoning/answerless.ts`). + * + * Otherwise the empty reply is thrown, tagged with a sentinel + * `httpStatus: 0` and its `kind` (v1.20.1) so the chain classifier can tell + * it apart from a transport failure (ECONNRESET, DNS, timeout). The cascade + * is unchanged: `isHardProviderFailure` treats `status <= 0` as hard. It + * carries what the reply cost, for the day's ledger to charge. + */ + private answerless( + params: CompletionParams, + reply: { + sent: string | null; + hadReasoning: boolean; + finishReason: string | null | undefined; + spent: number | null; + }, + ): Promise { + if ( + this.isGateway && + askAgainUnreasoned({ + key: this.reasoningDialectKey(), + provider: this.type, + signals: "ai.gateway", + sent: reply.sent, + hadReasoning: reply.hadReasoning, + finishReason: reply.finishReason, + }) + ) { + return withEarlierSpend(this.generateCompletion(params), reply.spent); + } + const err = new Error( + `${this.isGateway ? "OpenAI-compatible gateway" : "OpenAI"} returned empty content`, + ); + Object.assign(err, { + httpStatus: 0, + kind: reply.hadReasoning ? "reasoning_only" : "empty_response", + upstream: this.isGateway ? "openai-compatible" : "openai", + ...(reply.spent !== null ? { tokensUsed: reply.spent } : {}), + }); + throw err; + } + // ── v1.41 reasoning ─────────────────────────────────────────────────────── /** diff --git a/src/lib/ai/provider-runner.ts b/src/lib/ai/provider-runner.ts index 8bca7cd9a..c4bd364c8 100644 --- a/src/lib/ai/provider-runner.ts +++ b/src/lib/ai/provider-runner.ts @@ -13,6 +13,12 @@ import { type ProviderFailure, type ProviderFailureKind, } from "./failure-kind"; +import { spentTokensOf } from "./reasoning/answerless"; +import { + partitionForBackgroundWork, + signalBackgroundBench, + type BenchedProvider, +} from "./background-bench"; import { isOperatorFundedProvider, readDailySpend, @@ -182,9 +188,15 @@ export interface FallbackHop { httpStatus: number | null; /** * #1267 — what the call ran into (`failure-kind.ts`). Absent on a hop that - * never called the provider (the operator cost cap). + * never called the provider (the operator cost cap); `paused` on one that + * background work skipped (#1279). */ failureKind?: ProviderFailureKind; + /** + * #1279 — tokens the failed call spent upstream, when its reply said so + * (an answer that never came still billed its reasoning). + */ + tokensSpent?: number; } /** @@ -205,6 +217,12 @@ export class AllProvidersFailedError extends Error { * the thing that broke. */ readonly primaryCredentialExpired: boolean; + /** + * #1279 — tokens the failed hops spent upstream, summed. A caller that + * reserved budget charges this rather than refunding the whole reservation: + * a model that reasons without answering is paid for every time. + */ + readonly tokensSpent: number; constructor(attempts: FallbackHop[]) { super( @@ -214,6 +232,10 @@ export class AllProvidersFailedError extends Error { ); this.name = "AllProvidersFailedError"; this.attempts = attempts; + this.tokensSpent = attempts.reduce( + (sum, a) => sum + (a.tokensSpent ?? 0), + 0, + ); const first = attempts[0]; this.primaryCredentialExpired = first !== undefined && @@ -305,7 +327,11 @@ async function resolveChainOrder( userId: string, providers: ProviderChainResolved[], ledger: ProviderHealthLedger, -): Promise { + surface: BudgetSurface, +): Promise<{ + ordered: ProviderChainResolved[]; + benched: Array>; +}> { const skips = await ledger.getSkipHints(userId); if (skips.size > 0) { annotate({ @@ -317,8 +343,13 @@ async function resolveChainOrder( }, }); } - const afterSkips = applyHealthLedgerSkips(providers, skips); - return applyLastWorkingCache(userId, afterSkips); + // #1279 — background work leaves a benched provider out entirely. + const { walkable, benched } = + surface === "job" + ? partitionForBackgroundWork(providers, skips, (t) => NEVER_SKIP.has(t)) + : { walkable: providers, benched: [] }; + const afterSkips = applyHealthLedgerSkips(walkable, skips); + return { ordered: applyLastWorkingCache(userId, afterSkips), benched }; } function summariseError(e: unknown): { @@ -514,10 +545,36 @@ async function runRawChain( throw new AllProvidersFailedError([]); } - const ordered = await resolveChainOrder(userId, providers, ledger); + const { ordered, benched } = await resolveChainOrder( + userId, + providers, + ledger, + surface, + ); const hops: FallbackHop[] = []; const failedHops: HopSignal[] = []; + // #1279 — background work skips a provider the ledger benched; no request + // is sent. The skip is recorded after the walked hops, so a chain left + // with nothing fails as `AllProvidersFailedError` like any other, and it + // is logged once per window. + const benchedHops: FallbackHop[] = benched.map(({ candidate }, i) => ({ + providerType: candidate.providerType, + attempt: ordered.length + i + 1, + failureReason: "benched-for-background-work", + httpStatus: null, + failureKind: "paused", + })); + for (const { candidate, hint } of benched) { + annotate({ + meta: { + ai_chain_background_benched: candidate.providerType, + ai_chain_background_benched_reason: hint.reason, + }, + }); + signalBackgroundBench(userId, candidate.providerType, hint); + } + for (let i = 0; i < ordered.length; i += 1) { const candidate = ordered[i]; // v1.37.19 — hop-time operator-cost guard. A request whose @@ -621,12 +678,14 @@ async function runRawChain( ...failure, }); void ledger.recordFailure(userId, candidate.providerType, summary.status); + const spent = spentTokensOf(error); const hop: FallbackHop = { providerType: candidate.providerType, attempt: i + 1, failureReason: summary.reason, httpStatus: summary.status, failureKind: failure.failure, + ...(spent !== null ? { tokensSpent: spent } : {}), }; hops.push(hop); annotate({ @@ -648,7 +707,7 @@ async function runRawChain( }, }); signalFailedHops(failedHops, false, surface); - throw new AllProvidersFailedError(hops); + throw new AllProvidersFailedError([...hops, ...benchedHops]); } /** diff --git a/src/lib/ai/reasoning/answerless.ts b/src/lib/ai/reasoning/answerless.ts index 7d1de828b..0c16a9081 100644 --- a/src/lib/ai/reasoning/answerless.ts +++ b/src/lib/ai/reasoning/answerless.ts @@ -18,9 +18,11 @@ * work off a provider that keeps failing (`provider-runner.ts`), and each job * backs off the record it failed on. */ +import { emitSignal } from "@/lib/logging/signal"; import { ANSWERS_ONLY_UNREASONED, REASONS_REGARDLESS, + annotateReasoningDowngrade, learnedReasoningDialect, rememberReasoningDialect, type ReasoningDialectKey, @@ -60,6 +62,49 @@ export function nextAnswerlessStep( return { kind: "ask_unreasoned" }; } +/** + * The clients' whole answerless step: decide, mark the downgrade, and write + * the one line each lesson gets (`.reasoning_answerless` when the + * repeat is learned, `.reasoning_unswitchable` when it is learned + * useless), never one per call. True when the call goes out once more. + */ +export function askAgainUnreasoned(args: { + key: ReasoningDialectKey; + /** The provider tag for the downgrade mark (`local`, `openai-compatible`). */ + provider: string; + signals: "ai.local" | "ai.gateway"; + sent: string | null; + hadReasoning: boolean; + finishReason: string | null | undefined; +}): boolean { + const finish = + args.finishReason === "length" || args.finishReason === "stop" + ? args.finishReason + : "other"; + const step = nextAnswerlessStep(args.key, args.sent, args.hadReasoning); + if (step.kind === "final") { + if (step.learnedRegardless) { + emitSignal({ + action: `${args.signals}.reasoning_unswitchable`, + level: "warn", + meta: { finish }, + }); + } + return false; + } + annotateReasoningDowngrade(args.provider, args.sent ?? "default", "none"); + emitSignal({ + action: `${args.signals}.reasoning_answerless`, + level: "warn", + meta: { + effort: args.sent ?? "default", + finish, + reasoning: args.hadReasoning, + }, + }); + return true; +} + /** * True when the model has shown it reasons without being asked to, so a call * without a level of its own gets the thinking room (#1276). @@ -108,3 +153,16 @@ export function addSpentTokens(err: unknown, tokens: number | null): void { if (err === null || typeof err !== "object") return; Object.assign(err, { tokensUsed: (spentTokensOf(err) ?? 0) + tokens }); } + +/** + * Tokens a failed provider chain reported spending upstream + * (`AllProvidersFailedError.tokensSpent`), or 0 when it reported none. What a + * caller that reserved budget charges instead of a full refund: a model that + * reasons without answering is billed for every call. + */ +export function spentOnFailure(err: unknown): number { + const value = (err as { tokensSpent?: unknown } | null)?.tokensSpent; + return typeof value === "number" && Number.isFinite(value) && value > 0 + ? value + : 0; +} diff --git a/src/lib/documents/index-document.ts b/src/lib/documents/index-document.ts index 60afab046..5c6c25512 100644 --- a/src/lib/documents/index-document.ts +++ b/src/lib/documents/index-document.ts @@ -45,6 +45,7 @@ import { resolveDailyCap, type BudgetCostOwner, } from "@/lib/ai/coach/budget"; +import { spentTokensOf } from "@/lib/ai/reasoning/answerless"; import { loadOwnedDocument, prepareVisionInput, @@ -289,13 +290,22 @@ async function tryProviderIndex( outcome: { indexed: true, source: "vision", tokenCount }, note: null, }; - } catch { + } catch (err) { // Refund the reservation and let the caller fall through to local — a // transient provider miss must never leave a text-layer PDF unsearchable. - await reconcileSpend(userId, reservation.reserved, 0, dateKey, 0, { - servedBy: null, - reservedOwner: reservation.owner, - }); + // #1279 — what the reply reported spending stays charged: a model that + // reasons without answering bills every call. + await reconcileSpend( + userId, + reservation.reserved, + spentTokensOf(err) ?? 0, + dateKey, + 0, + { + servedBy: null, + reservedOwner: reservation.owner, + }, + ); return { outcome: null, note: "provider-error" }; } } diff --git a/src/lib/insights/__tests__/briefing-provider-budget.test.ts b/src/lib/insights/__tests__/briefing-provider-budget.test.ts index 9f578cb4d..508fba298 100644 --- a/src/lib/insights/__tests__/briefing-provider-budget.test.ts +++ b/src/lib/insights/__tests__/briefing-provider-budget.test.ts @@ -185,6 +185,17 @@ describe("runBriefingCompletion — ledger accounting", () => { expect(ledgerTotal).toBe(0); }); + it("charges what a failed chain reported spending (#1279)", async () => { + runRawCompletionWithFallback.mockRejectedValue( + Object.assign(new Error("chain exhausted"), { tokensSpent: 5400 }), + ); + + await expect(runBriefingCompletion(completionArgs())).rejects.toThrow( + "chain exhausted", + ); + expect(ledgerTotal).toBe(5400); + }); + it("re-throws the provider error unchanged so callers keep their mapping", async () => { class AllProvidersFailedError extends Error {} runRawCompletionWithFallback.mockRejectedValue( diff --git a/src/lib/insights/__tests__/status-provider-budget.test.ts b/src/lib/insights/__tests__/status-provider-budget.test.ts index bc6bdedb7..488c15501 100644 --- a/src/lib/insights/__tests__/status-provider-budget.test.ts +++ b/src/lib/insights/__tests__/status-provider-budget.test.ts @@ -312,6 +312,21 @@ describe("runStatusCompletion — ledger accounting", () => { expect(result.kind).toBe("error"); expect(ledgerTotal).toBe(0); }); + + it("charges what a failed chain reported spending (#1279)", async () => { + // A model that reasons and never answers is billed for every call; a + // full refund let background work spend without the ceiling seeing it. + runRawCompletionWithFallback.mockRejectedValue( + Object.assign(new Error("All 1 configured providers failed"), { + tokensSpent: 5400, + }), + ); + + const result = await runStatusCompletion(completionArgs()); + + expect(result.kind).toBe("error"); + expect(ledgerTotal).toBe(5400); + }); }); describe("runStatusCompletion — cost owner decides the ceiling", () => { diff --git a/src/lib/insights/briefing-provider.ts b/src/lib/insights/briefing-provider.ts index b8646a92c..d8ad8aa2d 100644 --- a/src/lib/insights/briefing-provider.ts +++ b/src/lib/insights/briefing-provider.ts @@ -35,6 +35,7 @@ import { type ProviderChainResolved, type RunRawWithFallbackResult, } from "@/lib/ai/provider-runner"; +import { spentOnFailure } from "@/lib/ai/reasoning/answerless"; import { buildDateKey, reconcileSpend, @@ -195,14 +196,23 @@ export async function runBriefingCompletion( }, }); } catch (err) { - // No usable reply: refund the whole reservation rather than bill an - // invented figure. A partially-burned upstream call is possible here, but - // we have no reported count to charge, and over-charging a failed - // generation would ration the retry the user is entitled to. - await reconcileSpend(args.userId, reservation.reserved, 0, dateKey, 0, { - servedBy: null, - reservedOwner: reservation.owner, - }).catch(() => { + // No usable reply: refund the reservation rather than bill an invented + // figure. A partially-burned upstream call is possible here, but without + // a reported count there is nothing to charge, and over-charging a + // failed generation would ration the retry the user is entitled to. + // #1279 — what the hops did report spending is charged: a model that + // reasons without answering bills every call. + await reconcileSpend( + args.userId, + reservation.reserved, + spentOnFailure(err), + dateKey, + 0, + { + servedBy: null, + reservedOwner: reservation.owner, + }, + ).catch(() => { // Best-effort: a failed refund leaves the conservative reservation in // place (never an undercount) and must not mask the provider error. }); diff --git a/src/lib/insights/status-provider.ts b/src/lib/insights/status-provider.ts index 5dd56a26c..edea35c09 100644 --- a/src/lib/insights/status-provider.ts +++ b/src/lib/insights/status-provider.ts @@ -12,6 +12,7 @@ import { runRawCompletionWithFallback, type ProviderChainResolved, } from "@/lib/ai/provider-runner"; +import { spentOnFailure } from "@/lib/ai/reasoning/answerless"; import { aiEgressRefusal } from "@/lib/ai/capabilities/egress"; import { annotate } from "@/lib/logging/context"; import { @@ -340,22 +341,17 @@ export async function runStatusCompletion( null, ); - if (raced.timedOut) { - // A timed-out generation may still have burned upstream tokens, but we have - // no reported count to charge — refund the reservation rather than bill an - // invented figure. - await reconcileSpend(userId, reservation.reserved, 0, dateKey, 0, { + if (raced.timedOut || raced.errored || raced.value === null) { + // A timeout or failure: charge only what a reply reported spending, never + // an invented figure. #1279 — a failed chain's report counts: a model + // that reasons without answering bills every call, and a full refund let + // background work spend without the day's ceiling ever seeing it. + const spent = spentOnFailure(raced.error); + await reconcileSpend(userId, reservation.reserved, spent, dateKey, 0, { servedBy: null, reservedOwner: reservation.owner, }); - return { kind: "timeout" }; - } - if (raced.errored || raced.value === null) { - await reconcileSpend(userId, reservation.reserved, 0, dateKey, 0, { - servedBy: null, - reservedOwner: reservation.owner, - }); - return { kind: "error" }; + return { kind: raced.timedOut ? "timeout" : "error" }; } const { result, workingProvider } = raced.value; diff --git a/src/lib/insights/with-timeout.ts b/src/lib/insights/with-timeout.ts index c194a844d..dc760fe4f 100644 --- a/src/lib/insights/with-timeout.ts +++ b/src/lib/insights/with-timeout.ts @@ -26,6 +26,8 @@ export interface TimeoutEnvelope { /** True when the upstream rejected before the budget expired. */ errored: boolean; value: T; + /** What the upstream rejected with, when `errored`. */ + error?: unknown; } export function withTimeout( @@ -83,7 +85,7 @@ export function withTimeout( action: { name: "insights.status.provider_error" }, meta: { reason: reason.slice(0, 240) }, }); - resolve({ timedOut: false, errored: true, value: fallback }); + resolve({ timedOut: false, errored: true, value: fallback, error }); }); }); }