From ec9c0fbe6a24c0948be7123a3e15b07f81ad6aec Mon Sep 17 00:00:00 2001 From: thesujai Date: Mon, 19 Oct 2026 20:54:26 +0530 Subject: [PATCH] feat: add request ID correlation for Body Timeout logs in VercelAILLM --- .changeset/llm-body-timeout-request-id.md | 5 ++ .../src/core/llm/VercelAILLM.ts | 59 ++++++++++++++++++- .../tests/core/llm/VercelAILLM.stream.test.ts | 41 +++++++++++++ 3 files changed, 102 insertions(+), 3 deletions(-) create mode 100644 .changeset/llm-body-timeout-request-id.md diff --git a/.changeset/llm-body-timeout-request-id.md b/.changeset/llm-body-timeout-request-id.md new file mode 100644 index 000000000..9aa0d5591 --- /dev/null +++ b/.changeset/llm-body-timeout-request-id.md @@ -0,0 +1,5 @@ +--- +'@truefoundry/trueforge-core': patch +--- + +Stamp `x-tfy-request-id` on each model call and log that id with model name and gateway URL on Body Timeout so harness logs can be correlated with AI Gateway traces. diff --git a/packages/trueforge-core/src/core/llm/VercelAILLM.ts b/packages/trueforge-core/src/core/llm/VercelAILLM.ts index 71cfdc8d1..923111f34 100644 --- a/packages/trueforge-core/src/core/llm/VercelAILLM.ts +++ b/packages/trueforge-core/src/core/llm/VercelAILLM.ts @@ -27,6 +27,7 @@ import type { UserContent, } from 'ai'; import { APICallError, jsonSchema, Output, streamText } from 'ai'; +import { randomUUID } from 'node:crypto'; import type { ChatCompletionContentPart, ChatCompletionCreateParamsStreaming, @@ -34,18 +35,21 @@ import type { ChatCompletionTool, } from 'openai/resources/chat'; import type { Logger } from 'winston'; -import { describeUnknownError, extractErrorLogFields } from '../util/errorLogFields'; +import { describeUnknownError, extractErrorLogFields, type ErrorLogFields } from '../util/errorLogFields'; import { modelSsrfFetch } from '../util/outboundFetch'; import type { ILLM, LLMCreateParams, LLMCreateParamsStreaming } from './ILLM'; import { + getEmptyUsage, type CompletionUsage, type ExtendedChatCompletionChunk, - getEmptyUsage, type RawAssistantMessage, type RawAssistantMessageWithUsage, type ThinkingBlock, } from './LLMTypes'; +/** Correlates harness model calls with TrueFoundry AI Gateway request traces. */ +export const X_TFY_REQUEST_ID = 'x-tfy-request-id'; + // --------------------------------------------------------------------------- // Public config // --------------------------------------------------------------------------- @@ -1380,6 +1384,27 @@ export async function* mapStreamToChunks({ // VercelAILLM // --------------------------------------------------------------------------- +/** True when undici idle-between-chunks bodyTimeout fired (nested under fetch failures). */ +export function isBodyTimeoutError(error: unknown): boolean { + return extractErrorLogFields(error).error.includes('Body Timeout'); +} + +/** Fields for Body Timeout logs: gateway correlation id plus model and URL when known. */ +export function bodyTimeoutLogFields(input: { + error: unknown; + tfyRequestId: string; + model: string; + gatewayUrl: string | undefined; +}): ErrorLogFields & { tfy_request_id: string; model: string; gateway_url?: string } { + const fields = extractErrorLogFields(input.error); + return { + ...fields, + tfy_request_id: input.tfyRequestId, + model: input.model, + ...(input.gatewayUrl !== undefined ? { gateway_url: input.gatewayUrl } : {}), + }; +} + /** ILLM implementation backed by Vercel AI SDK, supporting multiple LLM providers. */ export class VercelAILLM implements ILLM { private readonly config: VercelAILLMConfig; @@ -1395,7 +1420,15 @@ export class VercelAILLM implements ILLM { async *create( body: LLMCreateParamsStreaming, ): AsyncGenerator { - const { providerConfig } = this.config; + // Per-call id on x-tfy-request-id so Body Timeout (and gateway traces) can be correlated. + const tfyRequestId = randomUUID(); + const providerConfig: VercelAIProviderConfig = { + ...this.config.providerConfig, + headers: { + ...this.config.providerConfig.headers, + [X_TFY_REQUEST_ID]: tfyRequestId, + }, + }; const languageModel = buildLanguageModel(providerConfig); const { provider, model } = providerConfig; @@ -1451,6 +1484,16 @@ export class VercelAILLM implements ILLM { } catch (error) { if (this.signal?.aborted) { this.logger.debug('LLM call aborted', extractErrorLogFields(error)); + } else if (isBodyTimeoutError(error)) { + this.logger.error( + 'LLM Body Timeout', + bodyTimeoutLogFields({ + error, + tfyRequestId, + model: providerConfig.name, + gatewayUrl: providerConfig.baseUrl, + }), + ); } else { this.logger.error('Error creating streaming chat completion', extractErrorLogFields(error)); } @@ -1489,6 +1532,16 @@ export class VercelAILLM implements ILLM { } catch (error) { if (this.signal?.aborted) { this.logger.debug('LLM stream aborted', extractErrorLogFields(error)); + } else if (isBodyTimeoutError(error)) { + this.logger.error( + 'LLM Body Timeout', + bodyTimeoutLogFields({ + error, + tfyRequestId, + model: providerConfig.name, + gatewayUrl: providerConfig.baseUrl, + }), + ); } else { this.logger.error('Error reading LLM stream', extractErrorLogFields(error)); } diff --git a/packages/trueforge-core/tests/core/llm/VercelAILLM.stream.test.ts b/packages/trueforge-core/tests/core/llm/VercelAILLM.stream.test.ts index 6435bfcdd..864d0709a 100644 --- a/packages/trueforge-core/tests/core/llm/VercelAILLM.stream.test.ts +++ b/packages/trueforge-core/tests/core/llm/VercelAILLM.stream.test.ts @@ -13,7 +13,9 @@ import type { import { APICallError } from 'ai'; import type { ExtendedChatCompletionChunk, RawAssistantMessageWithUsage } from '../../../src/core/llm/LLMTypes'; import { + bodyTimeoutLogFields, describeStreamError, + isBodyTimeoutError, mapFinishReason, mapStreamToChunks, normalizeUsage, @@ -680,3 +682,42 @@ describe('mapStreamToChunks', () => { expect(nonFinishChunks).toHaveLength(0); }); }); + +// ─────────── Body Timeout correlation ─────────── + +describe('isBodyTimeoutError / bodyTimeoutLogFields', () => { + it('detects nested undici Body Timeout causes', () => { + const error = new TypeError('fetch failed', { + cause: new Error('Body Timeout Error', { cause: { code: 'UND_ERR_BODY_TIMEOUT' } }), + }); + expect(isBodyTimeoutError(error)).toBe(true); + expect(isBodyTimeoutError(new Error('Headers Timeout Error'))).toBe(false); + }); + + it('includes tfy_request_id, model, and gateway_url for gateway correlation', () => { + const error = new Error('Body Timeout Error'); + expect( + bodyTimeoutLogFields({ + error, + tfyRequestId: 'req-abc', + model: 'truefoundry/acct/gpt', + gatewayUrl: 'https://gateway.example/v1', + }), + ).toMatchObject({ + error: 'Body Timeout Error', + tfy_request_id: 'req-abc', + model: 'truefoundry/acct/gpt', + gateway_url: 'https://gateway.example/v1', + }); + }); + + it('omits gateway_url when the provider has no base URL', () => { + const fields = bodyTimeoutLogFields({ + error: new Error('Body Timeout Error'), + tfyRequestId: 'req-abc', + model: 'openai/gpt', + gatewayUrl: undefined, + }); + expect(fields).not.toHaveProperty('gateway_url'); + }); +});