From 27c9aade458822e57f2c63fcdf8e7e558d0c12c4 Mon Sep 17 00:00:00 2001 From: 1395490241lhj-code <1395490241lhj-code@users.noreply.github.com> Date: Tue, 20 Oct 2026 20:36:29 -0400 Subject: [PATCH 1/2] fix(server): add standalone Kitchen AI failure diagnostics Log safe upstream failure metadata on /api/ai-conversation so production provider_unavailable failures can be classified: status, reason, fallbackReason, timeoutSource, requestSizeBytes, primaryProvider, timeoutMs and a format-checked upstreamRequestId alongside the existing provider/attempt fields. Upstream codes are normalised to a short identifier pattern and request ids that fail the pattern are dropped. Upstream error bodies, keys, tokens, prompts and conversation content are never logged. No change to provider selection, models, fallback, timeouts, rate limits or the stream events returned to clients. Co-Authored-By: Claude Opus 5.5 --- server.js | 46 +++++++++- test/ai-conversation-stream.test.mjs | 122 +++++++++++++++++++++++++++ 2 files changed, 166 insertions(+), 2 deletions(-) diff --git a/server.js b/server.js index d58d87dd..961a7267 100644 --- a/server.js +++ b/server.js @@ -1291,6 +1291,28 @@ function cleanAiChatContent(content) { // Which layer ended the request: our own SDK deadline, or the provider's own // gateway timeout. Shared by the primary-attempt and final failure logs. +// The logger allowlist names fields; it does not vet their values. Upstream error +// codes and request ids are third-party strings, so before they reach a log line +// they must be short safe identifiers: an unexpected code is normalised, an +// unexpected request id is dropped. +const SAFE_UPSTREAM_CODE = /^[A-Za-z0-9][A-Za-z0-9_.-]{0,63}$/; +const SAFE_UPSTREAM_REQUEST_ID = /^[A-Za-z0-9_-]{8,128}$/; + +function safeUpstreamCode(code) { + if (code === undefined || code === null || code === '') return undefined; + const text = String(code); + return SAFE_UPSTREAM_CODE.test(text) ? text : 'unrecognized'; +} + +function safeUpstreamRequestId(id) { + const text = typeof id === 'string' ? id : ''; + return SAFE_UPSTREAM_REQUEST_ID.test(text) ? text : undefined; +} + +function safeUpstreamStatus(status) { + return Number.isInteger(status) && status >= 100 && status <= 599 ? status : undefined; +} + function aiTimeoutSource(info) { if (info.code === 'ECONNABORTED') return 'server_sdk_deadline'; return info.status === 504 ? 'upstream_response' : undefined; @@ -1589,6 +1611,10 @@ app.post('/api/ai-conversation', async (req, res) => { let answeredProvider = primaryConfig.provider; let answeredAttempt = 1; let failureCode = null; + // 失败时只保留可安全记录的分类：上游状态、上游错误码、上游请求 id。detail（上游 + // 错误正文）可能含 key 片段或 prompt 回显，永远不取。 + let upstreamFailure = null; + let primaryFailure = null; // 客户端断开才中止上游。请求体读完**不是**断开信号：express.json() 把 body 读完 // 之后 req 立刻 close（此时 req.complete === true），每个正常请求都会走到那里， // 拿它当断开信号会在响应还开着的时候掐掉一条健康的流。真正的断开只有两种： @@ -1641,8 +1667,13 @@ app.post('/api/ai-conversation', async (req, res) => { } catch (err) { if (clientAborted) break; failureCode = 'provider_unavailable'; + const info = getUpstreamAiErrorInfo(err); // 换 provider 只允许发生在第一个用户可见事件之前：已经发出去的内容不能重放。 - if (visibleEvents === 0 && index + 1 < attempts.length && isTransientProviderFailure(err)) continue; + if (visibleEvents === 0 && index + 1 < attempts.length && isTransientProviderFailure(err)) { + primaryFailure = info; + continue; + } + upstreamFailure = info; writeConversationEvent(res, streamErrorEvent('provider_unavailable')); visibleEvents += 1; break; @@ -1662,8 +1693,19 @@ app.post('/api/ai-conversation', async (req, res) => { attempt: answeredAttempt, fallbackTriggered: answeredAttempt > 1, durationMs: Date.now() - startedAt, - resultCode: clientAborted ? 'client_aborted' : (failureCode || 'success') + resultCode: clientAborted ? 'client_aborted' : (failureCode || 'success'), + primaryProvider: primaryConfig.provider, + timeoutMs: attempts[answeredAttempt - 1].timeout, + // 只有字节数，不含内容：用来判断失败是否与请求体积相关（上下文预加载、工具结果）。 + requestSizeBytes: Buffer.byteLength(JSON.stringify(conversationRequest.messages), 'utf8') }; + if (primaryFailure) logFields.fallbackReason = safeUpstreamCode(primaryFailure.code); + if (upstreamFailure) { + logFields.status = safeUpstreamStatus(upstreamFailure.status); + logFields.reason = safeUpstreamCode(upstreamFailure.code); + logFields.timeoutSource = aiTimeoutSource(upstreamFailure); + logFields.upstreamRequestId = safeUpstreamRequestId(upstreamFailure.upstreamRequestId); + } if (failureCode && !clientAborted) observabilityLogger.log('ai_conversation_failed', 'warn', logFields); else observabilityLogger.log('ai_conversation_completed', logFields); }); diff --git a/test/ai-conversation-stream.test.mjs b/test/ai-conversation-stream.test.mjs index 758cc6c5..66bbe320 100644 --- a/test/ai-conversation-stream.test.mjs +++ b/test/ai-conversation-stream.test.mjs @@ -783,3 +783,125 @@ test('ai-conversation 服务只承认计划中的十二个工具名', async () = assert.equal(selected[0].function.name, 'read_inventory'); assert.throws(() => selectConversationTools(['read_inventory', 'rm_rf']), (err) => err.publicStatus === 400 && err.publicCode === 'unsupported_tool'); }); +async function captureConversationLog(run) { + let logLines = ''; + const originalWrite = process.stdout.write; + process.stdout.write = (line) => { logLines += String(line); return true; }; + try { + await run(); + } finally { + process.stdout.write = originalWrite; + } + const entries = logLines.split('\n').filter(Boolean).map((line) => { + try { return JSON.parse(line); } catch { return null; } + }).filter(Boolean); + return { logLines, entries: entries.filter((entry) => String(entry.event).startsWith('ai_conversation_')) }; +} + +test('/api/ai-conversation 失败日志带上安全的失败分类，并区分首个 provider 的原因', async () => { + class APIConnectionTimeoutError extends Error {} + const rateLimited = async () => { + throw Object.assign(new Error('quota exceeded for gemini-secret'), { + status: 429, + error: { code: 'rate_limit_exceeded', message: 'quota exceeded for gemini-secret' } + }); + }; + const fallbackTimeout = async () => { throw new APIConnectionTimeoutError('Request timed out.'); }; + const { logLines, entries } = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ + env: { AI_CHAT_PROVIDER: 'gemini', GEMINI_API_KEY: 'gemini-secret' }, + streams: [rateLimited, fallbackTimeout] + }); + const res = await runPost(app, '/api/ai-conversation', { ...VALID_BODY, provider: 'gemini' }); + assert.equal(providerCalls.length, 2); + assert.deepEqual(events(res), [{ type: 'error', code: 'provider_unavailable', message: 'AI 服务暂时不可用。' }]); + }); + + assert.equal(entries.length, 1); + const entry = entries[0]; + assert.equal(entry.event, 'ai_conversation_failed'); + assert.equal(entry.resultCode, 'provider_unavailable'); + assert.equal(entry.primaryProvider, 'gemini'); + assert.equal(entry.provider, 'groq'); + assert.equal(entry.attempt, 2); + assert.equal(entry.fallbackTriggered, true); + assert.equal(entry.fallbackReason, 'rate_limit_exceeded'); + assert.equal(entry.status, 504); + assert.equal(entry.reason, 'ECONNABORTED'); + assert.equal(entry.timeoutSource, 'server_sdk_deadline'); + assert.equal(entry.timeoutMs, 20000); + assert.ok(Number.isInteger(entry.requestSizeBytes) && entry.requestSizeBytes > 0); + assert.equal(logLines.includes('gemini-secret'), false); + assert.equal(logLines.includes('quota exceeded'), false); + assert.equal(logLines.includes('今晚想吃清淡一点'), false); +}); + +test('/api/ai-conversation 不切换 provider 的失败同样记录上游状态与错误码', async () => { + const tooLarge = async () => { + throw Object.assign(new Error('Request too large: tokens per minute limit'), { + status: 413, + error: { code: 'rate_limit_exceeded', message: 'Request too large: tokens per minute limit' } + }); + }; + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [tooLarge] }); + await runPost(app, '/api/ai-conversation', VALID_BODY); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].event, 'ai_conversation_failed'); + assert.equal(entries[0].provider, 'groq'); + assert.equal(entries[0].attempt, 1); + assert.equal(entries[0].fallbackTriggered, false); + assert.equal(entries[0].fallbackReason, undefined); + assert.equal(entries[0].status, 413); + assert.equal(entries[0].reason, 'rate_limit_exceeded'); + assert.equal(entries[0].timeoutMs, 45000); + assert.equal(logLines.includes('Request too large'), false); +}); + +// 白名单只限制字段名，不限制字段值：上游的错误码与请求 id 是第三方返回的任意字符串， +// 进日志之前必须是短的安全标识，否则归一化（错误码）或丢弃（请求 id）。 +test('/api/ai-conversation 失败日志只记录安全格式的上游错误码与请求 id', async () => { + const hostileHeaders = new Map([['x-request-id', 'req id with spaces and gemini-secret']]); + const hostile = async () => { + throw Object.assign(new Error('boom'), { + status: 400, + error: { code: 'invalid value for user prompt: 今晚想吃清淡一点 gemini-secret', message: 'x' }, + response: { status: 400, headers: { get: (name) => hostileHeaders.get(name) ?? null } } + }); + }; + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ + env: { AI_CHAT_PROVIDER: 'gemini', GEMINI_API_KEY: 'gemini-secret' }, + streams: [hostile] + }); + await runPost(app, '/api/ai-conversation', { ...VALID_BODY, provider: 'gemini' }); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].status, 400); + assert.equal(entries[0].reason, 'unrecognized'); + assert.equal(entries[0].upstreamRequestId, undefined); + assert.equal(logLines.includes('gemini-secret'), false); + assert.equal(logLines.includes('今晚想吃清淡一点'), false); +}); + +test('/api/ai-conversation 首个 provider 的失败原因同样经过归一化', async () => { + const hostilePrimary = async () => { + throw Object.assign(new Error('boom'), { status: 503, error: { code: 'Service Unavailable: retry later' } }); + }; + const fallbackOk = streamOf([textChunk('备用回答'), finishChunk('stop')]); + const { entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ + env: { AI_CHAT_PROVIDER: 'gemini', GEMINI_API_KEY: 'test-gemini-key' }, + streams: [hostilePrimary, fallbackOk] + }); + await runPost(app, '/api/ai-conversation', { ...VALID_BODY, provider: 'gemini' }); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].event, 'ai_conversation_completed'); + assert.equal(entries[0].fallbackTriggered, true); + assert.equal(entries[0].fallbackReason, 'unrecognized'); +}); From 966dc979ad9fbb1d1e85f73a5f9841401f76ff5b Mon Sep 17 00:00:00 2001 From: 1395490241lhj-code <1395490241lhj-code@users.noreply.github.com> Date: Tue, 20 Oct 2026 22:47:23 -0400 Subject: [PATCH 2/2] fix(server): make AI failure diagnostics exception-safe and status-accurate S1: /api/ai-conversation now extracts failure diagnostics with its own conversationFailureInfo helper instead of the shared getUpstreamAiErrorInfo. Every field is read through a guarded accessor (throwing getters and Proxy traps read as unreadable), non-string error codes are never stringified, and an outer try/catch falls back to a fixed category. A malformed upstream error can no longer turn a handled provider_unavailable into an unhandled rejection on the no-fallback, fallback-attempt or mid-stream paths. S2: the logged status is only an integer 100-599 the error itself carries (err.response.status or the SDK's err.status). Transport errors, SDK timeouts and mid-stream errors without a status omit it instead of logging a synthetic 502/504. timeoutSource still separates server_sdk_deadline from a real upstream 504. The request id is the first well-formed value of x-groq-id, x-request-id or x-trace-id (err.response.headers or the SDK's err.headers), then err.requestID. Malformed values are skipped. Only the error body's code/type fields are read, never its message text. Unchanged: getUpstreamAiErrorInfo and every other route, the fallback decision (isTransientProviderFailure), provider calls, timeouts, rate limits and the client NDJSON events. Ten new regression tests use the real openai SDK error classes. Eight of them fail on e6cc48c (4 route throws, 4 synthetic statuses) and pass with this change. Co-Authored-By: Claude Opus 5.5 --- server.js | 124 ++++++++++--- test/ai-conversation-stream.test.mjs | 257 ++++++++++++++++++++++++++- 2 files changed, 360 insertions(+), 21 deletions(-) diff --git a/server.js b/server.js index 961a7267..cfd25cf4 100644 --- a/server.js +++ b/server.js @@ -1291,31 +1291,112 @@ function cleanAiChatContent(content) { // Which layer ended the request: our own SDK deadline, or the provider's own // gateway timeout. Shared by the primary-attempt and final failure logs. +function aiTimeoutSource(info) { + if (info.code === 'ECONNABORTED') return 'server_sdk_deadline'; + return info.status === 504 ? 'upstream_response' : undefined; +} + +// /api/ai-conversation failure diagnostics. They read a few primitive fields off +// the thrown error and never throw themselves: a diagnostic must not turn a handled +// provider failure into an unhandled rejection. The shared getUpstreamAiErrorInfo +// is not used here because it String()s arbitrary error codes (an object code can +// throw) and invents a 502/504 for errors that carried no HTTP status. // The logger allowlist names fields; it does not vet their values. Upstream error // codes and request ids are third-party strings, so before they reach a log line // they must be short safe identifiers: an unexpected code is normalised, an -// unexpected request id is dropped. +// unexpected request id is dropped. Only the body's code/type fields are read; +// its message text never is. const SAFE_UPSTREAM_CODE = /^[A-Za-z0-9][A-Za-z0-9_.-]{0,63}$/; const SAFE_UPSTREAM_REQUEST_ID = /^[A-Za-z0-9_-]{8,128}$/; +const UNREADABLE = Symbol('unreadable'); -function safeUpstreamCode(code) { - if (code === undefined || code === null || code === '') return undefined; - const text = String(code); +// A getter or Proxy trap may throw on access; such a field reads as UNREADABLE. +function readErrorField(target, key) { + if (target === null || (typeof target !== 'object' && typeof target !== 'function')) return undefined; + try { + return target[key]; + } catch { + return UNREADABLE; + } +} + +function isPresentField(value) { + return value === UNREADABLE || Boolean(value); +} + +// Only string or finite-number codes are kept. Anything else becomes a fixed +// category and is never stringified. +function safeFailureCode(value) { + let text = ''; + if (typeof value === 'string') text = value; + else if (typeof value === 'number' && Number.isFinite(value)) text = String(value); return SAFE_UPSTREAM_CODE.test(text) ? text : 'unrecognized'; } -function safeUpstreamRequestId(id) { - const text = typeof id === 'string' ? id : ''; - return SAFE_UPSTREAM_REQUEST_ID.test(text) ? text : undefined; +// Only a status the error itself carries from an HTTP response counts. Transport +// failures and SDK timeouts have none, so the field is omitted for them. +function failureHttpStatus(err) { + const candidates = [readErrorField(readErrorField(err, 'response'), 'status'), readErrorField(err, 'status')]; + return candidates.find((status) => Number.isInteger(status) && status >= 100 && status <= 599); } -function safeUpstreamStatus(status) { - return Number.isInteger(status) && status >= 100 && status <= 599 ? status : undefined; +// Same precedence as getUpstreamAiErrorInfo: response body error, SDK error body, +// then the error's own code/type; an SDK timeout with no code is ECONNABORTED. +function failureReason(err) { + const data = readErrorField(readErrorField(err, 'response'), 'data'); + const dataError = readErrorField(data, 'error'); + const sdkError = readErrorField(err, 'error'); + let upstreamError = null; + if (typeof dataError === 'object' && dataError !== null) upstreamError = dataError; + else if (typeof sdkError === 'object' && sdkError !== null) upstreamError = sdkError; + const code = [ + readErrorField(upstreamError, 'code'), + readErrorField(upstreamError, 'type'), + readErrorField(data, 'code'), + readErrorField(err, 'code'), + readErrorField(err, 'type') + ].find(isPresentField); + if (code !== undefined) return safeFailureCode(code); + const constructorName = readErrorField(readErrorField(err, 'constructor'), 'name'); + return constructorName === 'APIConnectionTimeoutError' ? 'ECONNABORTED' : 'upstream_error'; } -function aiTimeoutSource(info) { - if (info.code === 'ECONNABORTED') return 'server_sdk_deadline'; - return info.status === 504 ? 'upstream_response' : undefined; +function failureHeader(headers, name) { + try { + if (headers === null || typeof headers !== 'object') return undefined; + if (typeof headers.get === 'function') return headers.get(name); + const key = Object.keys(headers).find((candidate) => candidate.toLowerCase() === name); + return key === undefined ? undefined : headers[key]; + } catch { + return undefined; + } +} + +// The first well-formed id wins; malformed ones are skipped, never logged. The SDK +// keeps response headers on err.headers and x-request-id on err.requestID. +function failureRequestId(err) { + const headerSources = [readErrorField(readErrorField(err, 'response'), 'headers'), readErrorField(err, 'headers')]; + const candidates = []; + for (const name of ['x-groq-id', 'x-request-id', 'x-trace-id']) { + for (const headers of headerSources) candidates.push(failureHeader(headers, name)); + } + candidates.push(readErrorField(err, 'requestID')); + return candidates.find((id) => typeof id === 'string' && SAFE_UPSTREAM_REQUEST_ID.test(id)); +} + +function conversationFailureInfo(err) { + try { + const status = failureHttpStatus(err); + const reason = failureReason(err); + return { + status, + reason, + timeoutSource: aiTimeoutSource({ code: reason, status }), + upstreamRequestId: failureRequestId(err) + }; + } catch { + return { reason: 'unrecognized' }; + } } // 只记录限流后端与剩余时间，用来在生产上证明限流走的是共享 store 而不是每实例 @@ -1611,8 +1692,8 @@ app.post('/api/ai-conversation', async (req, res) => { let answeredProvider = primaryConfig.provider; let answeredAttempt = 1; let failureCode = null; - // 失败时只保留可安全记录的分类：上游状态、上游错误码、上游请求 id。detail（上游 - // 错误正文）可能含 key 片段或 prompt 回显，永远不取。 + // 失败时只保留可安全记录的分类：错误对象自带的 HTTP 状态、规范化后的错误码、超时来源、 + // 上游请求 id。上游错误的消息文本可能含 key 片段或 prompt 回显，永远不读。 let upstreamFailure = null; let primaryFailure = null; // 客户端断开才中止上游。请求体读完**不是**断开信号：express.json() 把 body 读完 @@ -1667,7 +1748,9 @@ app.post('/api/ai-conversation', async (req, res) => { } catch (err) { if (clientAborted) break; failureCode = 'provider_unavailable'; - const info = getUpstreamAiErrorInfo(err); + // 诊断提取本身不会抛异常。下面的 isTransientProviderFailure 不在此列：它对畸形错误码 + // 仍可能抛出，这是本诊断之前就有的行为。 + const info = conversationFailureInfo(err); // 换 provider 只允许发生在第一个用户可见事件之前：已经发出去的内容不能重放。 if (visibleEvents === 0 && index + 1 < attempts.length && isTransientProviderFailure(err)) { primaryFailure = info; @@ -1697,14 +1780,15 @@ app.post('/api/ai-conversation', async (req, res) => { primaryProvider: primaryConfig.provider, timeoutMs: attempts[answeredAttempt - 1].timeout, // 只有字节数，不含内容：用来判断失败是否与请求体积相关（上下文预加载、工具结果）。 + // 只统计 messages，不含工具定义和模型参数，不等于发给 provider 的完整请求体积。 requestSizeBytes: Buffer.byteLength(JSON.stringify(conversationRequest.messages), 'utf8') }; - if (primaryFailure) logFields.fallbackReason = safeUpstreamCode(primaryFailure.code); + if (primaryFailure) logFields.fallbackReason = primaryFailure.reason; if (upstreamFailure) { - logFields.status = safeUpstreamStatus(upstreamFailure.status); - logFields.reason = safeUpstreamCode(upstreamFailure.code); - logFields.timeoutSource = aiTimeoutSource(upstreamFailure); - logFields.upstreamRequestId = safeUpstreamRequestId(upstreamFailure.upstreamRequestId); + logFields.status = upstreamFailure.status; + logFields.reason = upstreamFailure.reason; + logFields.timeoutSource = upstreamFailure.timeoutSource; + logFields.upstreamRequestId = upstreamFailure.upstreamRequestId; } if (failureCode && !clientAborted) observabilityLogger.log('ai_conversation_failed', 'warn', logFields); else observabilityLogger.log('ai_conversation_completed', logFields); diff --git a/test/ai-conversation-stream.test.mjs b/test/ai-conversation-stream.test.mjs index 66bbe320..eb961e33 100644 --- a/test/ai-conversation-stream.test.mjs +++ b/test/ai-conversation-stream.test.mjs @@ -8,6 +8,9 @@ import path from 'node:path'; const require = createRequire(import.meta.url); const Module = require('node:module'); const originalLoad = Module._load; +// 真实 SDK 只用来构造错误对象：路由在生产上收到的就是这些类的实例。server.js 自己拿到的 +// 仍是下面 loadServerWithStreams 注入的 mock。 +const RealOpenAI = require('openai'); const root = process.cwd(); const serverPath = resolve(root, 'server.js'); const serverModulesDir = resolve(root, 'src/server') + path.sep; @@ -826,7 +829,8 @@ test('/api/ai-conversation 失败日志带上安全的失败分类，并区分 assert.equal(entry.attempt, 2); assert.equal(entry.fallbackTriggered, true); assert.equal(entry.fallbackReason, 'rate_limit_exceeded'); - assert.equal(entry.status, 504); + // SDK 自己的超时没有 HTTP 状态，不能记成合成的 504。 + assert.equal(entry.status, undefined); assert.equal(entry.reason, 'ECONNABORTED'); assert.equal(entry.timeoutSource, 'server_sdk_deadline'); assert.equal(entry.timeoutMs, 20000); @@ -905,3 +909,254 @@ test('/api/ai-conversation 首个 provider 的失败原因同样经过归一化' assert.equal(entries[0].fallbackTriggered, true); assert.equal(entries[0].fallbackReason, 'unrecognized'); }); + +// 下面的失败都用真实 openai SDK 的错误类构造：HTTP 状态在 err.status，错误码在 +// err.error.code / err.code，请求 id 在 err.requestID 与 err.headers（Headers 实例）。 +const SECRET_LIKE = 'gsk_live_secret_should_never_be_logged'; +const UPSTREAM_BODY = 'upstream body echo of the prompt'; +const INVENTORY_TEXT = '库存：鸡胸肉 2 块，西兰花 1 颗'; +const BODY_WITH_INVENTORY = { + ...VALID_BODY, + messages: [ + { role: 'user', content: '今晚想吃清淡一点' }, + { role: 'assistant', tool_calls: [{ id: 'call_inv', type: 'function', function: { name: 'read_inventory', arguments: '{}' } }] }, + { role: 'tool', tool_call_id: 'call_inv', content: INVENTORY_TEXT } + ] +}; +const PROVIDER_UNAVAILABLE = { type: 'error', code: 'provider_unavailable', message: 'AI 服务暂时不可用。' }; + +function sdkHttpError(status, error, requestId) { + const headers = new Headers(requestId === undefined ? {} : { 'x-request-id': requestId }); + return RealOpenAI.APIError.generate(status, { error }, undefined, headers); +} + +function throwing(err) { + return async () => { throw err; }; +} + +// JSON 能表达、但 String() 会抛 TypeError 的错误码。 +function unstringifiableCode() { + return JSON.parse('{"toString":1}'); +} + +function assertNoSensitiveLog(logLines) { + for (const needle of [SECRET_LIKE, UPSTREAM_BODY, '今晚想吃清淡一点', INVENTORY_TEXT, '鸡胸肉', 'test-groq-key', 'test-gemini-key']) { + assert.equal(logLines.includes(needle), false, `log must not contain ${needle}`); + } +} + +test('/api/ai-conversation 错误码无法转成字符串时诊断不抛异常，客户端照常收到 provider_unavailable', async () => { + const err = sdkHttpError(400, { code: unstringifiableCode(), message: `${UPSTREAM_BODY} ${SECRET_LIKE}` }, 'req_0123456789abcdef'); + const { logLines, entries } = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ streams: [throwing(err)] }); + const res = await runPost(app, '/api/ai-conversation', BODY_WITH_INVENTORY); + assert.equal(providerCalls.length, 1); + assert.equal(res.ended, true); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].event, 'ai_conversation_failed'); + assert.equal(entries[0].status, 400); + assert.equal(entries[0].reason, 'unrecognized'); + assert.equal(entries[0].upstreamRequestId, 'req_0123456789abcdef'); + assertNoSensitiveLog(logLines); +}); + +test('/api/ai-conversation 兜底那一次或流中途带着畸形错误码失败，诊断同样不抛异常', async () => { + const hostileFallback = sdkHttpError(503, { code: unstringifiableCode(), message: UPSTREAM_BODY }); + const fallbackRun = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ + env: { AI_CHAT_PROVIDER: 'gemini', GEMINI_API_KEY: 'test-gemini-key' }, + streams: [throwing(new RealOpenAI.APIConnectionError({ message: 'Connection error.' })), throwing(hostileFallback)] + }); + const res = await runPost(app, '/api/ai-conversation', { ...VALID_BODY, provider: 'gemini' }); + assert.equal(providerCalls.length, 2); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + assert.equal(fallbackRun.entries.length, 1); + assert.equal(fallbackRun.entries[0].attempt, 2); + assert.equal(fallbackRun.entries[0].fallbackReason, 'upstream_error'); + assert.equal(fallbackRun.entries[0].status, 503); + assert.equal(fallbackRun.entries[0].reason, 'unrecognized'); + assertNoSensitiveLog(fallbackRun.logLines); + + const midStream = async function* handler() { + yield textChunk('已经可见'); + throw new RealOpenAI.APIError(undefined, { code: unstringifiableCode(), message: UPSTREAM_BODY }, undefined, undefined); + }; + const midRun = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ streams: [midStream] }); + const res = await runPost(app, '/api/ai-conversation', VALID_BODY); + assert.equal(providerCalls.length, 1); + assert.deepEqual(events(res), [{ type: 'text_delta', text: '已经可见' }, PROVIDER_UNAVAILABLE]); + }); + assert.equal(midRun.entries.length, 1); + assert.equal(midRun.entries[0].status, undefined); + assert.equal(midRun.entries[0].reason, 'unrecognized'); + assertNoSensitiveLog(midRun.logLines); +}); + +test('/api/ai-conversation 错误对象的属性读取本身抛异常时，诊断也不抛', async () => { + const err = new Error(UPSTREAM_BODY); + for (const key of ['status', 'code', 'type', 'error', 'response', 'headers', 'requestID', 'constructor']) { + Object.defineProperty(err, key, { get() { throw new Error(`getter ${key} exploded ${SECRET_LIKE}`); } }); + } + const { logLines, entries } = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ streams: [throwing(err)] }); + const res = await runPost(app, '/api/ai-conversation', VALID_BODY); + assert.equal(providerCalls.length, 1); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].event, 'ai_conversation_failed'); + assert.equal(entries[0].status, undefined); + assert.equal(entries[0].reason, 'unrecognized'); + assert.equal(entries[0].upstreamRequestId, undefined); + assertNoSensitiveLog(logLines); +}); + +test('/api/ai-conversation 没有 HTTP 状态的网络错误不记合成的 502', async () => { + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [throwing(new RealOpenAI.APIConnectionError({ message: 'Connection error.' }))] }); + const res = await runPost(app, '/api/ai-conversation', VALID_BODY); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].status, undefined); + assert.equal(entries[0].reason, 'upstream_error'); + assert.equal(entries[0].timeoutSource, undefined); + assertNoSensitiveLog(logLines); +}); + +test('/api/ai-conversation SDK 自身超时不记合成的 504；上游真实 504 才记 504', async () => { + const sdkTimeout = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [throwing(new RealOpenAI.APIConnectionTimeoutError())] }); + await runPost(app, '/api/ai-conversation', VALID_BODY); + }); + assert.equal(sdkTimeout.entries.length, 1); + assert.equal(sdkTimeout.entries[0].status, undefined); + assert.equal(sdkTimeout.entries[0].reason, 'ECONNABORTED'); + assert.equal(sdkTimeout.entries[0].timeoutSource, 'server_sdk_deadline'); + + const gatewayTimeout = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ + streams: [throwing(sdkHttpError(504, { type: 'gateway_timeout', message: UPSTREAM_BODY }, 'req_gateway_timeout_1'))] + }); + await runPost(app, '/api/ai-conversation', VALID_BODY); + }); + assert.equal(gatewayTimeout.entries.length, 1); + assert.equal(gatewayTimeout.entries[0].status, 504); + assert.equal(gatewayTimeout.entries[0].reason, 'gateway_timeout'); + assert.equal(gatewayTimeout.entries[0].timeoutSource, 'upstream_response'); + assertNoSensitiveLog(sdkTimeout.logLines + gatewayTimeout.logLines); +}); + +test('/api/ai-conversation 真实 HTTP 400/413/429/503 的状态与错误码原样记录', async () => { + const cases = [ + { status: 400, error: { type: 'invalid_request_error', code: 'tool_use_failed' }, reason: 'tool_use_failed' }, + { status: 400, error: { code: 400, status: 'INVALID_ARGUMENT' }, reason: '400' }, + { status: 413, error: { type: 'tokens', code: 'rate_limit_exceeded' }, reason: 'rate_limit_exceeded' }, + { status: 429, error: { type: 'requests', code: 'rate_limit_exceeded' }, reason: 'rate_limit_exceeded' }, + { status: 503, error: { type: 'internal_server_error' }, reason: 'internal_server_error' } + ]; + for (const item of cases) { + const err = sdkHttpError(item.status, { ...item.error, message: `${UPSTREAM_BODY} ${SECRET_LIKE}` }, 'req_01HXYZabcdef1234'); + const { logLines, entries } = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ streams: [throwing(err)] }); + const res = await runPost(app, '/api/ai-conversation', BODY_WITH_INVENTORY); + assert.equal(providerCalls.length, 1); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + assert.equal(entries.length, 1, `${item.status} ${item.reason}`); + assert.equal(entries[0].status, item.status); + assert.equal(entries[0].reason, item.reason); + assert.equal(entries[0].timeoutSource, undefined); + assert.equal(entries[0].upstreamRequestId, 'req_01HXYZabcdef1234'); + assertNoSensitiveLog(logLines); + } +}); + +test('/api/ai-conversation SDK 的请求 id 合法时记录，畸形或超长时丢弃', async () => { + const cases = [ + { id: 'req_01HXYZabcdef1234', logged: 'req_01HXYZabcdef1234' }, + { id: `req id with spaces ${SECRET_LIKE}`, logged: undefined }, + { id: 'r'.repeat(200), logged: undefined }, + { id: undefined, logged: undefined } + ]; + for (const item of cases) { + const err = sdkHttpError(429, { code: 'rate_limit_exceeded', message: UPSTREAM_BODY }, item.id); + assert.equal(err.requestID, item.id ?? null); + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [throwing(err)] }); + await runPost(app, '/api/ai-conversation', VALID_BODY); + }); + assert.equal(entries.length, 1); + assert.equal(entries[0].upstreamRequestId, item.logged); + assertNoSensitiveLog(logLines); + } +}); + +test('/api/ai-conversation 某个请求 id 头格式不对时，记录后面第一个格式正确的 id', async () => { + const headers = new Headers({ 'x-groq-id': `bad id ${SECRET_LIKE}`, 'x-request-id': 'req_0123456789abcdef' }); + const err = RealOpenAI.APIError.generate(429, { error: { code: 'rate_limit_exceeded', message: UPSTREAM_BODY } }, undefined, headers); + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [throwing(err)] }); + await runPost(app, '/api/ai-conversation', VALID_BODY); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].upstreamRequestId, 'req_0123456789abcdef'); + assertNoSensitiveLog(logLines); +}); + +// 单个字段读不出来只影响那一个字段：其余诊断照常记录，而不是整体退回兜底分类。 +test('/api/ai-conversation 只有一个字段读取抛异常时，其余诊断照常记录', async () => { + const idThrows = sdkHttpError(429, { code: 'rate_limit_exceeded', message: UPSTREAM_BODY }); + Object.defineProperty(idThrows, 'requestID', { get() { throw new Error(SECRET_LIKE); } }); + const codeThrows = Object.defineProperty(Object.assign(new Error(UPSTREAM_BODY), { status: 503 }), 'code', { + get() { throw new Error(SECRET_LIKE); } + }); + const cases = [ + { err: idThrows, status: 429, reason: 'rate_limit_exceeded' }, + { err: codeThrows, status: 503, reason: 'unrecognized' } + ]; + for (const item of cases) { + const { logLines, entries } = await captureConversationLog(async () => { + const { app } = loadServerWithStreams({ streams: [throwing(item.err)] }); + const res = await runPost(app, '/api/ai-conversation', VALID_BODY); + assert.deepEqual(events(res), [PROVIDER_UNAVAILABLE]); + }); + assert.equal(entries.length, 1); + assert.equal(entries[0].status, item.status); + assert.equal(entries[0].reason, item.reason); + assert.equal(entries[0].upstreamRequestId, undefined); + assertNoSensitiveLog(logLines); + } +}); + +test('/api/ai-conversation 流中途的失败没有 HTTP 状态时不记 status，事件与 provider 调用次数不变', async () => { + const midStream = async function* handler() { + yield textChunk('已经可见'); + throw new RealOpenAI.APIError(undefined, { code: 'server_error', message: UPSTREAM_BODY }, undefined, undefined); + }; + const { logLines, entries } = await captureConversationLog(async () => { + const { app, providerCalls } = loadServerWithStreams({ + env: { AI_CHAT_PROVIDER: 'gemini', GEMINI_API_KEY: 'test-gemini-key' }, + streams: [midStream, streamOf([textChunk('绝不应被调用'), finishChunk('stop')])] + }); + const res = await runPost(app, '/api/ai-conversation', { ...VALID_BODY, provider: 'gemini' }); + assert.equal(providerCalls.length, 1); + assert.deepEqual(events(res), [{ type: 'text_delta', text: '已经可见' }, PROVIDER_UNAVAILABLE]); + }); + + assert.equal(entries.length, 1); + assert.equal(entries[0].provider, 'gemini'); + assert.equal(entries[0].attempt, 1); + assert.equal(entries[0].fallbackTriggered, false); + assert.equal(entries[0].status, undefined); + assert.equal(entries[0].reason, 'server_error'); + assertNoSensitiveLog(logLines); +});