diff --git a/apps/insights/src/organization-business-context.test.ts b/apps/insights/src/organization-business-context.test.ts index a0293ae23..80f726290 100644 --- a/apps/insights/src/organization-business-context.test.ts +++ b/apps/insights/src/organization-business-context.test.ts @@ -34,6 +34,29 @@ afterEach(() => { else process.env.AUTUMN_SECRET_KEY = secret; }); +function clock() { + const started = Date.now(); + let elapsed = 0; + const timers: { at: number; controller: AbortController }[] = []; + spyOn(Date, "now").mockImplementation(() => started + elapsed); + spyOn(performance, "now").mockImplementation(() => elapsed); + spyOn(AbortSignal, "timeout").mockImplementation((ms) => { + const controller = new AbortController(); + timers.push({ at: elapsed + ms, controller }); + return controller.signal; + }); + return (ms: number) => { + elapsed += ms; + for (const timer of timers) { + if (timer.at <= elapsed) { + timer.controller.abort( + new DOMException("Test deadline", "TimeoutError") + ); + } + } + }; +} + function fixture( outputs: unknown[] = [ { paths: ["/pricing"] }, @@ -157,12 +180,12 @@ function fixture( const errors = spyOn(logs, "captureInsightsError").mockImplementation( () => {} ); - spyOn(logs, "emitInsightsEvent").mockImplementation(() => {}); + const events = spyOn(logs, "emitInsightsEvent").mockImplementation(() => {}); setAiRequestLoggerProvider(logs.getActiveInsightsLog); + const logger = logs.createInsightsEventLog({ test: true }); const run = () => - logs.withInsightsLogContext( - logs.createInsightsEventLog({ test: true }), - () => generateOrganizationBusinessContext(input) + logs.withInsightsLogContext(logger, () => + generateOrganizationBusinessContext(input) ); return { get state() { @@ -183,6 +206,8 @@ function fixture( billed, model, errors, + events, + logger, }; } @@ -225,6 +250,26 @@ describe("organization business context worker", () => { expect(JSON.stringify(synthesis)).toContain("savedContext"); expect(JSON.stringify(synthesis)).toContain(manual); expect(f.bill).toHaveBeenCalledTimes(2); + expect(f.logger.getContext().ai).toMatchObject({ + calls: 2, + inputTokens: 400, + outputTokens: 200, + totalTokens: 600, + }); + expect( + f.events.mock.calls + .filter( + ([, event]) => event === "organization_business_context.model_call" + ) + .map(([, , fields]) => ({ + phase: fields?.phase, + input: fields?.input_tokens, + output: fields?.output_tokens, + })) + ).toEqual([ + { phase: "selection", input: 200, output: 100 }, + { phase: "synthesis", input: 200, output: 100 }, + ]); expect( new Set(f.bill.mock.calls.map(([call]) => call.idempotencyKey)).size ).toBe(2); @@ -324,6 +369,11 @@ describe("organization business context worker", () => { expect(f.state.generation?.status).toBe("failed"); expect(f.state.profile?.content).toBe(manual); expect(f.bill).toHaveBeenCalledTimes(2); + expect(f.logger.getContext().ai).toMatchObject({ + calls: 2, + inputTokens: 400, + outputTokens: 200, + }); }); it.each([ @@ -331,6 +381,7 @@ describe("organization business context worker", () => { "expired", "ready", "failed", + "cancelled", ])("does no work for %s generation", async (condition) => { const f = fixture(); const generation = f.state.generation; @@ -342,12 +393,101 @@ describe("organization business context worker", () => { ).toISOString(); if (condition === "ready" || condition === "failed") generation.status = condition; + if (condition === "cancelled") f.state.generation = null; await f.run(); expect(f.site).not.toHaveBeenCalled(); expect(f.mark).not.toHaveBeenCalled(); expect(f.model.doGenerateCalls).toHaveLength(0); }); + it.each([ + "saved", + "cancelled", + "superseded", + "failed", + "ready", + ] as const)("stops after selection is %s, accounting for the consumed call", async (condition) => { + const f = fixture(); + const generate = f.model.doGenerate; + f.model.doGenerate = async (options) => { + const result = await generate(options); + if (!f.state.profile || !f.state.generation) + throw new Error("Missing fixture"); + if (condition === "saved") { + f.state.profile = { + ...f.state.profile, + content: "New team correction", + revision: 4, + }; + f.state.generation = null; + } + if (condition === "cancelled") f.state.generation = null; + if (condition === "superseded" && f.state.generation) + f.state.generation = { ...f.state.generation, id: "new-generation" }; + if ( + (condition === "failed" || condition === "ready") && + f.state.generation + ) + f.state.generation.status = condition; + return result; + }; + await f.run(); + expect(f.model.doGenerateCalls).toHaveLength(1); + expect(f.bill).toHaveBeenCalledTimes(1); + expect(f.read.mock.calls.map(([call]) => call.path)).toEqual(["/"]); + expect(f.mark).toHaveBeenCalledTimes(1); + expect(f.errors).not.toHaveBeenCalled(); + expect(f.logger.getContext().ai).toMatchObject({ + calls: 1, + inputTokens: 200, + outputTokens: 100, + }); + expect(f.state.profile?.content).toBe( + condition === "saved" ? "New team correction" : manual + ); + }); + + it.each([ + "credits", + "homepage", + "discovery", + "selected-page", + ] as const)("checks cancellation after %s before starting more reads or model calls", async (phase) => { + const f = fixture(); + if (phase === "credits") { + f.credits.mockImplementation(async () => { + f.state.generation = null; + return true; + }); + } + if (phase === "discovery") { + f.search.mockImplementation(async () => { + f.state.generation = null; + return { success: true, results: [] }; + }); + } + const read = f.read.getMockImplementation(); + if (!read) throw new Error("Missing page fixture"); + f.read.mockImplementation(async (...args) => { + const result = await read(...args); + if ( + (phase === "homepage" && args[0].path === "/") || + (phase === "selected-page" && args[0].path === "/pricing") + ) + f.state.generation = null; + return result; + }); + await f.run(); + expect(f.model.doGenerateCalls).toHaveLength( + phase === "selected-page" ? 1 : 0 + ); + expect(f.bill).toHaveBeenCalledTimes(phase === "selected-page" ? 1 : 0); + if (phase === "credits") expect(f.read).not.toHaveBeenCalled(); + if (phase === "homepage") expect(f.search).not.toHaveBeenCalled(); + expect(f.state.generation).toBeNull(); + expect(f.errors).not.toHaveBeenCalled(); + }); + it("does not read a deleted, transferred, or renamed source website", async () => { const f = fixture(); f.site.mockResolvedValue(undefined); @@ -473,13 +613,18 @@ describe("organization business context worker", () => { expect(f.model.doGenerateCalls).toHaveLength(0); }); - it("bounds a hanging source read and preserves saved content on timeout", async () => { + it.each([ + 0, 170_000, + ])("bounds a hanging source read with %i ms queue age", async (age) => { const f = fixture(); - const timeout = AbortSignal.timeout; - spyOn(AbortSignal, "timeout").mockImplementation((ms) => - timeout(ms === 115_000 ? 5 : ms) - ); - f.read.mockImplementation(() => new Promise(() => {})); + const advance = clock(); + if (!f.state.generation) throw new Error("Missing fixture generation"); + f.state.generation.requestedAt = new Date(Date.now() - age).toISOString(); + f.read.mockImplementation(({ abortSignal }) => { + advance(age ? 5000 : 115_000); + expect(abortSignal?.aborted).toBe(true); + return new Promise(() => {}); + }); await f.run(); expect(f.state.generation?.status).toBe("failed"); expect(f.state.generation?.error).toContain("too long"); @@ -487,6 +632,113 @@ describe("organization business context worker", () => { expect(f.model.doGenerateCalls).toHaveLength(0); }); + it("does not start work when only the persistence reserve remains", async () => { + const f = fixture(); + clock(); + if (!f.state.generation) throw new Error("Missing fixture generation"); + f.state.generation.requestedAt = new Date( + Date.now() - 175_000 + ).toISOString(); + await f.run(); + expect(f.state.generation?.status).toBe("failed"); + expect(f.state.generation?.error).toContain("too long"); + expect(f.site).not.toHaveBeenCalled(); + expect(f.read).not.toHaveBeenCalled(); + expect(f.bill).not.toHaveBeenCalled(); + }); + + it("stops before synthesis when selection uses the remaining request budget", async () => { + const f = fixture(); + const advance = clock(); + if (!f.state.generation) throw new Error("Missing fixture generation"); + f.state.generation.requestedAt = new Date( + Date.now() - 170_000 + ).toISOString(); + f.bill.mockImplementation(async (call) => { + advance(5000); + return f.billed(call); + }); + await f.run(); + expect(f.model.doGenerateCalls).toHaveLength(1); + expect(f.bill).toHaveBeenCalledTimes(1); + expect(f.read.mock.calls.map(([call]) => call.path)).toEqual(["/"]); + expect(f.state.generation?.status).toBe("failed"); + expect(f.state.generation?.error).toContain("too long"); + expect(f.state.generation?.draft).toBeNull(); + expect(f.logger.getContext().ai).toMatchObject({ + calls: 1, + inputTokens: 200, + outputTokens: 100, + }); + }); + + it("bounds the model by the request deadline after queue and source reads", async () => { + const f = fixture(); + const advance = clock(); + if (!f.state.generation) throw new Error("Missing fixture generation"); + f.state.generation.requestedAt = new Date( + Date.now() - 170_000 + ).toISOString(); + const read = f.read.getMockImplementation(); + if (!read) throw new Error("Missing page fixture"); + f.read.mockImplementation(async (...args) => { + advance(2000); + return await read(...args); + }); + const generate = f.model.doGenerate; + f.model.doGenerate = async (options) => { + const result = await generate(options); + advance(2999); + expect(options.abortSignal?.aborted).toBe(false); + advance(1); + expect(options.abortSignal?.aborted).toBe(true); + options.abortSignal?.throwIfAborted(); + return result; + }; + await f.run(); + expect(f.model.doGenerateCalls).toHaveLength(1); + expect(f.state.generation?.status).toBe("failed"); + expect(f.state.generation?.error).toContain("too long"); + expect(f.bill).not.toHaveBeenCalled(); + }); + + it("finishes consumed-call billing and persists within the reserve before request expiry", async () => { + const f = fixture(); + const advance = clock(); + if (!f.state.generation) throw new Error("Missing fixture generation"); + f.state.generation.requestedAt = new Date( + Date.now() - 170_000 + ).toISOString(); + const expiry = Date.now() + 10_000; + const generate = f.model.doGenerate; + f.model.doGenerate = async (options) => { + advance(2000); + expect(options.abortSignal?.aborted).toBe(false); + return await generate(options); + }; + f.bill.mockImplementation(async (call) => { + if (f.model.doGenerateCalls.length === 2) advance(4000); + return f.billed(call); + }); + const mark = f.mark.getMockImplementation(); + if (!mark) throw new Error("Missing persistence fixture"); + f.mark.mockImplementation(async (change) => { + if (change.status === "ready") { + expect(Date.now()).toBe(expiry - 2000); + advance(1000); + } + return await mark(change); + }); + await f.run(); + expect(f.model.doGenerateCalls).toHaveLength(2); + expect(f.model.doGenerateCalls[1]?.abortSignal?.aborted).toBe(true); + expect(f.bill).toHaveBeenCalledTimes(2); + expect(f.state.generation?.status).toBe("ready"); + expect(Date.now()).toBeLessThan(expiry); + expect(f.state.profile?.content).toBe(manual); + expect(f.errors).not.toHaveBeenCalled(); + }); + it("preserves saved manual text and the internal cause when the model fails", async () => { const f = fixture(); const failure = new Error("Synthetic model provider failure"); diff --git a/apps/insights/src/organization-business-context.ts b/apps/insights/src/organization-business-context.ts index af2792821..c55e2445c 100644 --- a/apps/insights/src/organization-business-context.ts +++ b/apps/insights/src/organization-business-context.ts @@ -86,8 +86,18 @@ export async function generateOrganizationBusinessContext( ): Promise { const input = generationSchema.parse(payload); const started = performance.now(); - // Reserve five seconds to persist a friendly failure within the 120s job budget. - const signal = AbortSignal.timeout(115_000); + let deadline = Date.now() + 120_000; + const remaining = (reserve = 0) => + Math.max( + 0, + Math.floor( + Math.min( + deadline - Date.now(), + 120_000 - (performance.now() - started) + ) - reserve + ) + ); + let signal = AbortSignal.timeout(115_000); const fields = { organization_id: input.organizationId, generation_id: input.generationId, @@ -110,6 +120,35 @@ export async function generateOrganizationBusinessContext( ) { return; } + deadline = Math.min( + deadline, + Date.parse(generation.requestedAt) + BUSINESS_CONTEXT_GENERATION_TIMEOUT + ); + // Queue age counts against the same deadline as the service. Reserve five + // seconds for consumed-call billing and persistence, including a friendly failure. + signal = AbortSignal.any([signal, AbortSignal.timeout(remaining(5000))]); + const settlement = AbortSignal.timeout(remaining()); + const available = () => { + signal.throwIfAborted(); + const ms = remaining(5000); + if (ms <= 0) { + throw new DOMException("Generation deadline reached", "TimeoutError"); + } + return ms; + }; + const current = async () => { + available(); + const latest = await bounded( + readOrganizationBusinessContext(input.organizationId), + signal + ); + available(); + return ( + latest.generation?.id === input.generationId && + latest.generation.status === "running" + ); + }; + available(); const site = await bounded( db.query.websites.findFirst({ where: { @@ -190,7 +229,7 @@ export async function generateOrganizationBusinessContext( usage, idempotencyKey, }), - signal + settlement ); if (logger.getContext().agent_usage_billing_error) { throw new Error("Business context usage billing failed", { @@ -233,10 +272,16 @@ export async function generateOrganizationBusinessContext( }); return result; }; + if (!(await current())) { + return; + } const home = await read("/"); if (!home) { throw new Error("No readable business homepage"); } + if (!(await current())) { + return; + } // Reuse the existing same-site search tool; discovery snippets are never evidence. const search = createScrapeTools().search_website; if (!search.execute) { @@ -297,13 +342,14 @@ export async function generateOrganizationBusinessContext( // AI SDK telemetry callbacks swallow thrown errors; check billing explicitly // after each call, before another read or making the draft available. let billingFailure: Error | undefined; + const model = getAILogger().wrap(createModelFromId(MODEL)); const options = (phase: string) => { const key = `org-business-context:${input.generationId}:${phase}:${randomUUID()}`; return { - model: getAILogger().wrap(createModelFromId(MODEL)), + model, maxRetries: 0, abortSignal: signal, - timeout: { totalMs: 45_000 }, + timeout: { totalMs: Math.min(45_000, available()) }, onStepFinish: async (step: { usage: LanguageModelUsage }) => { emitInsightsEvent( "info", @@ -325,6 +371,9 @@ export async function generateOrganizationBusinessContext( }; }; if (paths.length) { + if (!(await current())) { + return; + } const selected = await bounded( generateText({ ...options("selection"), @@ -339,11 +388,14 @@ export async function generateOrganizationBusinessContext( paths, }), }), - signal + settlement ); if (billingFailure) { throw billingFailure; } + if (!(await current())) { + return; + } const chosen = z.array(z.enum(paths)).max(6).parse(selected.output.paths); const results = await Promise.all([...new Set(chosen)].map(read)); pages = [ @@ -368,6 +420,9 @@ export async function generateOrganizationBusinessContext( .min(1) .max(7), }); + if (!(await current())) { + return; + } const compiled = await bounded( generateText({ ...options("synthesis"), @@ -394,7 +449,7 @@ export async function generateOrganizationBusinessContext( })), }), }), - signal + settlement ); if (billingFailure) { throw billingFailure; @@ -409,10 +464,9 @@ export async function generateOrganizationBusinessContext( title: page.title ?? page.finalUrl, })), }); - signal.throwIfAborted(); const ready = await bounded( markBusinessContextGeneration({ ...input, status: "ready", draft }), - signal + settlement ); if ( ready.generation?.id !== input.generationId || @@ -431,16 +485,17 @@ export async function generateOrganizationBusinessContext( "organization_business_context.generation_failed", fields ); - const remaining = Math.max(1, 120_000 - (performance.now() - started)); await bounded( markBusinessContextGeneration({ ...input, status: "failed", - error: signal.aborted - ? "Generation took too long. Try again; your saved context is unchanged." - : failure, + error: + signal.aborted || + (error instanceof Error && error.name === "TimeoutError") + ? "Generation took too long. Try again; your saved context is unchanged." + : failure, }), - AbortSignal.timeout(Math.floor(remaining)) + AbortSignal.timeout(Math.max(1, remaining())) ); } }