mirror of
https://github.com/MBombeck/HealthLog.git
synced 2026-11-08 12:32:43 +00:00
fix(insights): do not count a status run the bench sent nothing for
A status run whose whole chain was benched for background work sent no request, yet the caller opened the note's negative window as for any failure and raised its failure streak. The streak doubles the window up to two hours, so a note kept waiting long after its provider recovered. AllProvidersFailedError now says when no hop sent anything (sentNothing: every provider benched, or refused by the operator cost cap). The status chokepoint then holds the note for the first window without touching the streak (holdStatusNoteWhileBenched), and the caller's own failure write lands inside that window and neither moves nor counts it. A run that reached a provider counts as before. Refs #1279
This commit is contained in:
1 parent
b0ea3b1654
commit
f1163d5efb
8 files changed
+225
-53
No files matched your search
@@ -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": 350,
|
||||
"total": 113326,
|
||||
"total": 113317,
|
||||
"entries": {
|
||||
"app/achievements/page.tsx :: AchievementsPage": 206,
|
||||
"app/api/admin/backups/upload/route.ts :: apiHandler(arg)": 314,
|
||||
@@ -297,7 +297,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": 224,
|
||||
"lib/insights/status-provider.ts :: runStatusCompletion": 215,
|
||||
"lib/integrations/connection-health-load.ts :: loadConnectionFacts": 227,
|
||||
"lib/integrations/status.ts :: recordSyncFailure": 292,
|
||||
"lib/jobs/apple-health-import-worker.ts :: handleAppleHealthImport": 300,
|
||||
|
||||
@@ -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": 9262,
|
||||
"total": 9259,
|
||||
"entries": {
|
||||
"__tests__/account-payload-consumer-guard.test.ts": 2,
|
||||
"__tests__/acting-account-boundary-guard.test.ts": 7,
|
||||
@@ -1783,7 +1783,7 @@
|
||||
"lib/ai/prompts/weight.ts": 2,
|
||||
"lib/ai/provider-chain.ts": 1,
|
||||
"lib/ai/provider-health-ledger.ts": 3,
|
||||
"lib/ai/provider-runner.ts": 14,
|
||||
"lib/ai/provider-runner.ts": 11,
|
||||
"lib/ai/provider.ts": 10,
|
||||
"lib/ai/reasoning/__tests__/controls.test.ts": 1,
|
||||
"lib/ai/reasoning/controls.ts": 2,
|
||||
|
||||
@@ -111,6 +111,19 @@ describe("#1279: background work and a benched provider", () => {
|
||||
]);
|
||||
}
|
||||
expect(gateway.calls).toBe(HARD_FAILURE_SKIP_THRESHOLD);
|
||||
// The bench sent nothing; a hop that reached the provider did.
|
||||
const benched = await walk(
|
||||
"job",
|
||||
"u-bench",
|
||||
"openai-compatible",
|
||||
gateway,
|
||||
ledger,
|
||||
).then(
|
||||
() => null,
|
||||
(e: unknown) => e,
|
||||
);
|
||||
expect(benched).toBeInstanceOf(AllProvidersFailedError);
|
||||
expect((benched as AllProvidersFailedError).sentNothing).toBe(true);
|
||||
// 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({
|
||||
@@ -139,6 +152,7 @@ describe("#1279: background work and a benched provider", () => {
|
||||
expect((err as AllProvidersFailedError).attempts[0].failureKind).toBe(
|
||||
"reasoning_only",
|
||||
);
|
||||
expect((err as AllProvidersFailedError).sentNothing).toBe(false);
|
||||
});
|
||||
|
||||
it("walks the benched provider for a job-rationed call a person waits on", async () => {
|
||||
|
||||
@@ -38,50 +38,36 @@ import {
|
||||
const NEVER_SKIP: ReadonlySet<ProviderChainType> = new Set(["local"]);
|
||||
|
||||
/**
|
||||
* v1.4.16 — multi-provider redundancy runner.
|
||||
* The multi-provider redundancy runner: a provider completion with a
|
||||
* hard-failure walk across an ordered list of providers, so one provider's
|
||||
* outage (a 401 from an expired Codex sign-in, a 503 brown-out, a network
|
||||
* reset) cascades to the next configured provider instead of failing the
|
||||
* request.
|
||||
*
|
||||
* The chain runner wraps a provider completion with a hard-failure
|
||||
* walkthrough across an ordered list of providers. The motivation is
|
||||
* the maintainer's "ein Provider-Ausfall darf die Insights nicht zerschiessen"
|
||||
* mandate: a 401 from Codex (OAuth expired), a 503 from OpenAI
|
||||
* (upstream brown-out), or a network reset MUST cascade to the next
|
||||
* configured provider rather than 422-ing the whole request.
|
||||
* Hard failures (`isHardProviderFailure`) cascade. A malformed-JSON reply is
|
||||
* NOT a hard failure — it is a prompt-following issue, so it bubbles to the
|
||||
* caller's own validator rather than masking itself as provider
|
||||
* unavailability and walking the chain. Every provider receives the same
|
||||
* enriched system prompt; `outcome.workingProvider.providerType` attributes
|
||||
* feedback per provider.
|
||||
*
|
||||
* Hard failures (`isHardProviderFailure`) cascade. A malformed-JSON
|
||||
* reply is NOT a hard failure — it is a prompt-following issue, so it
|
||||
* bubbles to the caller's own validator rather than masking itself as
|
||||
* provider unavailability and walking the chain.
|
||||
*
|
||||
* Cross-feature coupling:
|
||||
* - B5a's `MEDICAL_REFERENCES` is shared via the system prompt; each
|
||||
* provider in the chain receives the same enriched context.
|
||||
* - B5e (planned v1.4.17) reads `outcome.workingProvider.providerType`
|
||||
* to attribute feedback per provider; that's why we re-export it
|
||||
* out of the runner instead of the wrapper.
|
||||
*
|
||||
* The cache: a provider that worked on the last call gets first crack
|
||||
* on the next, so a user whose Codex OAuth lapsed doesn't re-burn the
|
||||
* 401 round-trip on every request for the next hour. Cache is
|
||||
* in-process (per worker), keyed by `userId`, TTL 1h. No coordination
|
||||
* across workers — when scaling out we'd move this to Redis, but for
|
||||
* v1.4.16 the per-worker cache is enough to absorb the typical
|
||||
* "polling reload" pattern.
|
||||
*
|
||||
* v1.18.7 — DECISION: the volatile per-worker hint is left
|
||||
* in-process and NOT folded into the durable Postgres health ledger. The
|
||||
* ledger already shares the load-bearing signal across workers (the
|
||||
* skip-hint reorder in `resolveChainOrder` pushes a dead-credential /
|
||||
* backoff provider to the chain tail for every worker), so the only thing
|
||||
* The cache: a provider that worked on the last call gets first crack on the
|
||||
* next, so a user whose Codex sign-in lapsed doesn't re-burn the 401
|
||||
* round-trip on every request for the next hour. In-process (per worker),
|
||||
* keyed by `userId`, TTL 1h. It stays out of the durable Postgres health
|
||||
* ledger on purpose: the ledger already shares the load-bearing signal across
|
||||
* workers (the skip-hint reorder in `resolveChainOrder`), so the only thing
|
||||
* uncoordinated is a soft "tried this one last, put it first" reorder whose
|
||||
* worst case is a single redundant first-hop per worker per hour — exactly
|
||||
* the bound the v1.18.7 AI audit deemed acceptable at single-maintainer
|
||||
* scale. Promoting the hint to a per-request ledger write would add write
|
||||
* amplification on the hot path for a negligible saving; revisit only if a
|
||||
* multi-worker deploy shows measurable redundant-hop cost.
|
||||
* worst case is one redundant first hop per worker per hour. Promoting it to
|
||||
* a per-request ledger write would add write amplification on the hot path;
|
||||
* revisit only if a multi-worker deploy shows measurable redundant-hop cost.
|
||||
*/
|
||||
|
||||
const LAST_WORKING_TTL_MS = 60 * 60 * 1000; // 1h
|
||||
|
||||
/** The `failureReason` of a hop the operator cost cap refused unsent. */
|
||||
const OPERATOR_CAP_REFUSAL = "operator-cost-cap-exhausted";
|
||||
|
||||
interface CacheEntry {
|
||||
providerType: ProviderChainType;
|
||||
expiresAt: number;
|
||||
@@ -223,6 +209,13 @@ export class AllProvidersFailedError extends Error {
|
||||
* a model that reasons without answering is paid for every time.
|
||||
*/
|
||||
readonly tokensSpent: number;
|
||||
/**
|
||||
* #1279 — true when no hop sent a request: every provider was benched for
|
||||
* background work or refused by the operator cost cap. Such a failure says
|
||||
* nothing about what was asked, so a caller that backs off the record it
|
||||
* failed on does not count it.
|
||||
*/
|
||||
readonly sentNothing: boolean;
|
||||
|
||||
constructor(attempts: FallbackHop[]) {
|
||||
super(
|
||||
@@ -236,6 +229,13 @@ export class AllProvidersFailedError extends Error {
|
||||
(sum, a) => sum + (a.tokensSpent ?? 0),
|
||||
0,
|
||||
);
|
||||
this.sentNothing =
|
||||
attempts.length > 0 &&
|
||||
attempts.every(
|
||||
(a) =>
|
||||
a.failureKind === "paused" ||
|
||||
a.failureReason === OPERATOR_CAP_REFUSAL,
|
||||
);
|
||||
const first = attempts[0];
|
||||
this.primaryCredentialExpired =
|
||||
first !== undefined &&
|
||||
@@ -631,7 +631,7 @@ async function runRawChain(
|
||||
const hop: FallbackHop = {
|
||||
providerType: candidate.providerType,
|
||||
attempt: i + 1,
|
||||
failureReason: "operator-cost-cap-exhausted",
|
||||
failureReason: OPERATOR_CAP_REFUSAL,
|
||||
httpStatus: null,
|
||||
};
|
||||
hops.push(hop);
|
||||
|
||||
@@ -22,6 +22,7 @@ vi.mock("@/lib/db", () => ({
|
||||
import {
|
||||
STATUS_NEGATIVE_WINDOW_BASE_MS,
|
||||
clearStatusNegativeWindows,
|
||||
holdStatusNoteWhileBenched,
|
||||
statusNegativeWindowMs,
|
||||
statusNoteCoolingDown,
|
||||
writeStatusNegativeWindow,
|
||||
@@ -116,6 +117,57 @@ describe("writeStatusNegativeWindow", () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("holdStatusNoteWhileBenched", () => {
|
||||
// A run that sent nothing because every provider was benched says nothing
|
||||
// about the note: counting it left the note waiting up to two hours after
|
||||
// the provider recovered.
|
||||
it("opens the first window and leaves the streak as it was", async () => {
|
||||
findUnique.mockResolvedValue({ retryAt: new Date(Date.now() - MINUTE) });
|
||||
const before = Date.now();
|
||||
await holdStatusNoteWhileBenched({
|
||||
userId: "u1",
|
||||
cacheAction: "insights.weight-status.en",
|
||||
todayKey: TODAY,
|
||||
});
|
||||
const args = written();
|
||||
expect(args.update).not.toHaveProperty("failureStreak");
|
||||
expect(args.create).toMatchObject({ failureStreak: 0, dateKey: TODAY });
|
||||
const window = args.update.retryAt.getTime() - before;
|
||||
expect(window).toBeGreaterThanOrEqual(STATUS_NEGATIVE_WINDOW_BASE_MS);
|
||||
expect(window).toBeLessThan(STATUS_NEGATIVE_WINDOW_BASE_MS + MINUTE);
|
||||
});
|
||||
|
||||
it("leaves an open window alone, and the failure after it uncounted", async () => {
|
||||
findUnique.mockResolvedValue({
|
||||
retryAt: new Date(Date.now() + MINUTE),
|
||||
failureStreak: 3,
|
||||
});
|
||||
await holdStatusNoteWhileBenched({
|
||||
userId: "u1",
|
||||
cacheAction: "insights.weight-status.en",
|
||||
todayKey: TODAY,
|
||||
});
|
||||
await writeStatusNegativeWindow({
|
||||
userId: "u1",
|
||||
cacheAction: "insights.weight-status.en",
|
||||
todayKey: TODAY,
|
||||
reason: "error",
|
||||
});
|
||||
expect(upsert).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
it("never throws: a missed hold only lets the next failure count", async () => {
|
||||
findUnique.mockRejectedValue(new Error("pool exhausted"));
|
||||
await expect(
|
||||
holdStatusNoteWhileBenched({
|
||||
userId: "u1",
|
||||
cacheAction: "insights.weight-status.en",
|
||||
todayKey: TODAY,
|
||||
}),
|
||||
).resolves.toBeUndefined();
|
||||
});
|
||||
});
|
||||
|
||||
describe("statusNegativeWindowMs", () => {
|
||||
it("doubles from five minutes to a two-hour ceiling", () => {
|
||||
expect([1, 2, 3, 4, 5, 6, 7, 30].map(statusNegativeWindowMs)).toEqual(
|
||||
|
||||
@@ -60,6 +60,7 @@ vi.mock("@/lib/db", () => ({
|
||||
// #1279 — the note's negative window, read before any provider work.
|
||||
insightStatusCache: {
|
||||
findUnique: vi.fn(async () => noteWindow),
|
||||
upsert: vi.fn(async () => ({})),
|
||||
},
|
||||
},
|
||||
}));
|
||||
@@ -374,6 +375,36 @@ describe("runStatusCompletion — ledger accounting", () => {
|
||||
expect(again.kind).toBe("ok");
|
||||
});
|
||||
|
||||
it("holds the note without counting a run the bench sent nothing for (#1279)", async () => {
|
||||
runRawCompletionWithFallback.mockRejectedValue(
|
||||
Object.assign(new Error("All 1 configured providers failed"), {
|
||||
sentNothing: true,
|
||||
}),
|
||||
);
|
||||
const { prisma } = await import("@/lib/db");
|
||||
const result = await runStatusCompletion(
|
||||
completionArgs({ cacheAction: "insights.weight-status.en" }),
|
||||
);
|
||||
expect(result.kind).toBe("error");
|
||||
expect(prisma.insightStatusCache.upsert).toHaveBeenCalledWith(
|
||||
expect.objectContaining({
|
||||
create: expect.objectContaining({ failureStreak: 0 }),
|
||||
update: expect.not.objectContaining({
|
||||
failureStreak: expect.anything(),
|
||||
}),
|
||||
}),
|
||||
);
|
||||
});
|
||||
|
||||
it("leaves a run that reached a provider to the caller's counted window", async () => {
|
||||
runRawCompletionWithFallback.mockRejectedValue(new Error("upstream down"));
|
||||
const { prisma } = await import("@/lib/db");
|
||||
await runStatusCompletion(
|
||||
completionArgs({ cacheAction: "insights.weight-status.en" }),
|
||||
);
|
||||
expect(prisma.insightStatusCache.upsert).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
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.
|
||||
|
||||
@@ -72,6 +72,48 @@ export async function writeStatusNegativeWindow(args: {
|
||||
});
|
||||
}
|
||||
|
||||
/**
|
||||
* #1279 — hold a note while its chain sent nothing: every provider was
|
||||
* benched for background work (or refused by the operator cost cap). Such a
|
||||
* run says nothing about the note, and counting it left the note waiting up
|
||||
* to two hours after the provider recovered. Opens the first window unless
|
||||
* one is open and leaves the streak as it was, so the caller's own failure
|
||||
* write lands inside it and neither moves nor counts. Best-effort: a missed
|
||||
* hold only lets that write count.
|
||||
*/
|
||||
export async function holdStatusNoteWhileBenched(args: {
|
||||
userId: string;
|
||||
cacheAction: string;
|
||||
todayKey: string;
|
||||
}): Promise<void> {
|
||||
const key = statusCacheKey(args.cacheAction);
|
||||
if (!key) return;
|
||||
const where = { userId_metric_locale: { userId: args.userId, ...key } };
|
||||
try {
|
||||
const row = await prisma.insightStatusCache.findUnique({
|
||||
where,
|
||||
select: { retryAt: true },
|
||||
});
|
||||
const now = Date.now();
|
||||
if (row?.retryAt && row.retryAt.getTime() > now) return;
|
||||
const retryAt = new Date(now + STATUS_NEGATIVE_WINDOW_BASE_MS);
|
||||
await prisma.insightStatusCache.upsert({
|
||||
where,
|
||||
create: {
|
||||
userId: args.userId,
|
||||
...key,
|
||||
dateKey: args.todayKey,
|
||||
retryAt,
|
||||
negativeReason: "error",
|
||||
failureStreak: 0,
|
||||
},
|
||||
update: { retryAt, negativeReason: "error" },
|
||||
});
|
||||
} catch {
|
||||
// The caller's own write still opens a window.
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* True while the note's negative-cache window is open. #1279 — checked right
|
||||
* before a status generation reaches a provider (`runStatusCompletion`), so
|
||||
|
||||
@@ -21,6 +21,7 @@ import {
|
||||
reserveBudget,
|
||||
resolveCostOwner,
|
||||
resolveDailyCapFor,
|
||||
type BudgetCostOwner,
|
||||
} from "@/lib/ai/coach/budget";
|
||||
import {
|
||||
AI_BUDGETS,
|
||||
@@ -36,7 +37,10 @@ import {
|
||||
type BackgroundReasoningJob,
|
||||
} from "@/lib/ai/reasoning/levels";
|
||||
import { resolveJobReasoning } from "@/lib/ai/reasoning/controls";
|
||||
import { statusNoteCoolingDown } from "./status-negative-window";
|
||||
import {
|
||||
holdStatusNoteWhileBenched,
|
||||
statusNoteCoolingDown,
|
||||
} from "./status-negative-window";
|
||||
|
||||
/**
|
||||
* v1.41 — the fallback ceiling for a status-path call that reasons. Thinking
|
||||
@@ -332,16 +336,7 @@ export async function runStatusCompletion(
|
||||
);
|
||||
|
||||
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: raced.timedOut ? "timeout" : "error" };
|
||||
return failedRun(raced, { userId, cacheAction, dateKey, reservation });
|
||||
}
|
||||
|
||||
const { result, workingProvider, tokensSpent } = raced.value;
|
||||
@@ -395,6 +390,44 @@ export async function runStatusCompletion(
|
||||
};
|
||||
}
|
||||
|
||||
/**
|
||||
* A run that timed out or failed. It charges only what a reply reported
|
||||
* spending, never an invented figure; #1279 — a failed chain's report counts,
|
||||
* since a model that reasons without answering bills every call, and a full
|
||||
* refund let background work spend without the day's ceiling seeing it. A
|
||||
* chain that sent nothing (the bench) holds the note without counting it.
|
||||
*/
|
||||
async function failedRun(
|
||||
raced: { timedOut: boolean; error?: unknown },
|
||||
run: {
|
||||
userId: string;
|
||||
cacheAction: string;
|
||||
dateKey: string;
|
||||
reservation: { reserved: number; owner: BudgetCostOwner };
|
||||
},
|
||||
): Promise<StatusProviderResult> {
|
||||
const spent = spentOnFailure(raced.error);
|
||||
await reconcileSpend(
|
||||
run.userId,
|
||||
run.reservation.reserved,
|
||||
spent,
|
||||
run.dateKey,
|
||||
0,
|
||||
{
|
||||
servedBy: null,
|
||||
reservedOwner: run.reservation.owner,
|
||||
},
|
||||
);
|
||||
if ((raced.error as { sentNothing?: unknown } | null)?.sentNothing === true) {
|
||||
await holdStatusNoteWhileBenched({
|
||||
userId: run.userId,
|
||||
cacheAction: run.cacheAction,
|
||||
todayKey: run.dateKey,
|
||||
});
|
||||
}
|
||||
return { kind: raced.timedOut ? "timeout" : "error" };
|
||||
}
|
||||
|
||||
/**
|
||||
* Over the day's ceiling. Reported as `error` — a TRANSIENT miss the caller
|
||||
* serves the fallback for without persisting it — deliberately NOT `none`,
|
||||
|
||||
Reference in new issue
Block a user