diff --git a/doc/alarms.md b/doc/alarms.md index 5d098c76e..ed9f78922 100644 --- a/doc/alarms.md +++ b/doc/alarms.md @@ -78,6 +78,11 @@ this.clients.alarm.create(alarmId, message, fields, 'critical', { The HTTP error handler uses it: its id is route + error signature, so a hot loop of the same crash is one incident with N occurrences instead of N pages. +Dedup and Slack's repeat throttle mean a responder sees only the latest +occurrence, so the handler attaches the `HttpError`'s `fields` to the alarm as +`details` — put what a responder needs (which upstreams failed, and how) +there. Everything in `fields` is also returned to the client in the response +body, so it has to be safe to show the caller. Reach for it anywhere else only when the id is that specific — otherwise a per-request alarm can flood the pager. diff --git a/src/backend/core/http/HttpError.ts b/src/backend/core/http/HttpError.ts index 73329db83..e2dbd9280 100644 --- a/src/backend/core/http/HttpError.ts +++ b/src/backend/core/http/HttpError.ts @@ -98,7 +98,11 @@ export interface HttpErrorOptions { * expect. */ code?: string; - /** Additional fields merged into the response body. */ + /** + * Additional fields merged into the response body, and attached to the + * alarm as `details` when the error alarms. Everything here reaches the + * client, so it has to be safe to show the caller. + */ fields?: Record; /** * Skip the terminal alarm gate for this error. Set it only where the call diff --git a/src/backend/drivers/ai-chat/ChatCompletionDriver.edges.test.ts b/src/backend/drivers/ai-chat/ChatCompletionDriver.edges.test.ts index bd7bf474c..272af255d 100644 --- a/src/backend/drivers/ai-chat/ChatCompletionDriver.edges.test.ts +++ b/src/backend/drivers/ai-chat/ChatCompletionDriver.edges.test.ts @@ -270,10 +270,19 @@ describe('ChatCompletionDriver exhausted-chain classification', () => { // `fake` is priced at zero throughout: an upstream throttle there is // expected and costs nobody anything, so the caller still gets the // 429 but nothing is recorded. + const warn = vi + .spyOn(console, 'warn') + .mockImplementation(() => undefined); const err = await errorFor( Object.assign(new Error('slow down'), { status: 429 }), ); expect(err.noAlarm).toBe(true); + // Nothing to act on means nothing to log either. + expect( + warn.mock.calls.some((c) => + String(c[0]).startsWith('[ai-chat] all routes failed'), + ), + ).toBe(false); }); it('keeps the alarm when a paid model is the one being rate limited', async () => { diff --git a/src/backend/drivers/ai-chat/ChatCompletionDriver.test.ts b/src/backend/drivers/ai-chat/ChatCompletionDriver.test.ts index a966c6b8c..7801911ad 100644 --- a/src/backend/drivers/ai-chat/ChatCompletionDriver.test.ts +++ b/src/backend/drivers/ai-chat/ChatCompletionDriver.test.ts @@ -1152,6 +1152,9 @@ describe('ChatCompletionDriver.complete fallback and error envelope', () => { vi.spyOn(FakeChatProvider.prototype, 'complete').mockRejectedValue( new Error('boom'), ); + const warn = vi + .spyOn(console, 'warn') + .mockImplementation(() => undefined); let caught: HttpError | undefined; try { @@ -1178,6 +1181,15 @@ describe('ChatCompletionDriver.complete fallback and error envelope', () => { provider: 'fake-chat', error: 'boom', }); + + // The alarm collapses every occurrence onto one message, so the + // per-route detail has to be logged per request or it is lost. + const line = warn.mock.calls + .map((c) => String(c[0])) + .find((l) => l.startsWith('[ai-chat] all routes failed')); + expect(line).toContain('fake-chat:fake'); + expect(line).toContain('internal_error'); + expect(line).toContain(JSON.stringify(attempts)); }); it('hands every fallback attempt the same messages array, reasoning artifacts intact', async () => { diff --git a/src/backend/drivers/ai-chat/ChatCompletionDriver.ts b/src/backend/drivers/ai-chat/ChatCompletionDriver.ts index ee3d051a4..d154dcc16 100644 --- a/src/backend/drivers/ai-chat/ChatCompletionDriver.ts +++ b/src/backend/drivers/ai-chat/ChatCompletionDriver.ts @@ -584,7 +584,15 @@ export class ChatCompletionDriver extends PuterDriver { if (!res) { await hold.release(); - throw classifyAttempts(attempts, { allModelsFree }); + const failure = classifyAttempts(attempts, { allModelsFree }); + // A deduped alarm shows only its latest occurrence, so each + // request's per-route failures are logged here, under its trace. + if (!failure.noAlarm) { + console.warn( + `[ai-chat] all routes failed (${completionId}, ${model.provider}:${model.id}, ${failure.legacyCode}): ${JSON.stringify(attempts)}`, + ); + } + throw failure; } const username = actor.user?.username; diff --git a/src/backend/server.test.ts b/src/backend/server.test.ts index 8418ea89a..8a5d0fb76 100644 --- a/src/backend/server.test.ts +++ b/src/backend/server.test.ts @@ -20,7 +20,16 @@ import http from 'node:http'; import type { Request, RequestHandler, Response } from 'express'; -import { afterAll, afterEach, beforeAll, describe, expect, it } from 'vitest'; +import { + afterAll, + afterEach, + beforeAll, + describe, + expect, + it, + vi, +} from 'vitest'; +import { HttpError } from './core/http/HttpError.ts'; import { extensionStore } from './extensions.ts'; import { PuterServer } from './server.ts'; import { allocateEphemeralPort, setupTestServer } from './testUtil.ts'; @@ -479,3 +488,100 @@ describe('PuterServer route option validation', () => { } }); }); + +/** + * Dedup and repeat throttling mean a responder sees only an alarm's latest + * occurrence, so what a thrower attached in `fields` has to travel with each + * one — and a plain Error has to keep raising the same alarm without it. + */ +describe('PuterServer HTTP alarm gate', () => { + let server: PuterServer; + let port: number; + + const attempts = [ + { model: 'm', provider: 'a', error: 'boom' }, + { model: 'm', provider: 'b', status: 502, error: 'bad gateway' }, + ]; + + beforeAll(async () => { + extensionStore.routeHandlers.push( + { + method: 'get', + path: '/explode', + options: {}, + handler: (() => { + throw new HttpError(500, 'All providers failed', { + legacyCode: 'internal_error', + // Same names as the gate's own fields, which must + // stay the HTTP status and the thrown error. + fields: { attempts, status: 'theirs', error: 'theirs' }, + }); + }) as unknown as RequestHandler, + }, + { + method: 'get', + path: '/plain', + options: {}, + handler: (() => { + throw new Error('kaboom'); + }) as unknown as RequestHandler, + }, + ); + port = await allocateEphemeralPort(); + server = await setupTestServer( + { + port, + domain: 'puter.localhost', + origin: `http://puter.localhost:${port}`, + } as unknown as IConfig, + { listen: true }, + ); + }); + + afterAll(async () => { + extensionStore.routeHandlers.length = 0; + await server?.shutdown(); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + const raisedFor = async (path: string) => { + const alarm = vi + .spyOn(server.clients.alarm, 'create') + .mockImplementation(() => undefined); + const res = await rawRequest(port, path, { host: 'puter.localhost' }); + expect(res.status).toBe(500); + const raised = alarm.mock.calls.find((c) => + String(c[0]).startsWith(`http_500:GET:${path}:`), + ); + expect(raised).toBeTruthy(); + return { + id: raised![0] as string, + fields: raised![2] as Record, + }; + }; + + it("attaches an HttpError's fields as `details` without touching its own", async () => { + const { id, fields } = await raisedFor('/explode'); + expect(id).toBe( + 'http_500:GET:/explode:internal_error:All providers failed', + ); + expect(fields.details).toEqual({ + attempts, + status: 'theirs', + error: 'theirs', + }); + expect(fields.status).toBe(500); + expect(fields.error).toBeInstanceOf(HttpError); + }); + + it('raises the same alarm for a plain Error, with no details', async () => { + const { id, fields } = await raisedFor('/plain'); + expect(id).toBe('http_500:GET:/plain:kaboom'); + expect(fields.status).toBe(500); + expect(fields.error).toBeInstanceOf(Error); + expect(fields).not.toHaveProperty('details'); + }); +}); diff --git a/src/backend/server.ts b/src/backend/server.ts index 014b53f67..3c5ffe270 100644 --- a/src/backend/server.ts +++ b/src/backend/server.ts @@ -838,6 +838,14 @@ export class PuterServer { alarmId, `HTTP ${status} on ${req.method} ${req.originalUrl}: ${signature}`, { + // What the thrower attached (an AI chain's + // per-provider attempts, say) rides under one key + // so it can't shadow the request fields below, and + // a repeat from another thrower on the same id + // replaces it rather than merging into it. + ...(isHttp && err.fields !== undefined + ? { details: err.fields } + : {}), error: err instanceof Error ? err : undefined, status, method: req.method,