diff --git a/.env.example b/.env.example index a3243d6c..dfe0992e 100644 --- a/.env.example +++ b/.env.example @@ -638,3 +638,13 @@ ALLOW_PRIVATE_PROXY_HOSTS= # WINDSURFAPI_NO_OPEN=1 # gRPC 传输协议;'connect' 走 Connect 协议,默认走 gRPC。仅影响 Cascade 路径。 # GRPC_PROTOCOL=connect + +# --- Reasoning/content 边界泄漏追踪 (实验性,默认 OFF) --- +# WINDSURFAPI_LEAK_TRACE=1 +# 输出 LEAK_TRACE 前缀的结构化日志,用于在线抓取"模型推理(thinking)泄漏进 +# content 通道"的活体问题(#238/#241/#243 只做了 rescue 与 ` thinking` 重排, +# 从未在强制复现中抓到泄漏本身)。每个流事件记:channel(content/reasoning)、 +# think(命中的标记,如 / ◁think▷)、sample(截断样本,非全文)、 +# len、reqId/account;messages 路径记 block-start/classify(blockType/channel/ +# msgId/reqId);settle 时记 contentChars/reasoningChars/rerouted。默认 OFF: +# 关闭时热路径只读一次 env 标志,不改任何行为。 diff --git a/README.md b/README.md index 1e540459..c2eda7c5 100644 --- a/README.md +++ b/README.md @@ -275,6 +275,7 @@ curl http://localhost:3003/v1/messages \ | `DEFAULT_MODEL` | `claude-sonnet-4.6` | 不传 model 用哪个。必须是当前后端能解析的名字 —— connect 上解析不到的名字会静默降级成免费 selector | | `MAX_TOKENS` | `8192` | 默认最大回复 token 数 | | `LOG_LEVEL` | `info` | debug / info / warn / error | +| `WINDSURFAPI_LEAK_TRACE` | off | 推理/内容边界结构化日志(实验性,默认关闭)。开启后输出 `LEAK_TRACE` 前缀日志:原始流事件所属通道(content/reasoning)、think 标记、截断文本样本、settle 时 content/reasoning 字符数。用于在线抓取模型推理泄漏进 content 通道的问题。字段:channel/blockType/think/sample/len/reqId/account/msgId/contentChars/reasoningChars/rerouted | | `WINDSURFAPI_IGNORE_CLOUD_FILTER` | `0` | Cascade 路径下，各账号云端 catalog 同步后，账号池列表展示活跃账号目录的并集，路由则校验所选账号自己的目录；设为 `1` 恢复完整静态 catalog。目录缺失、为空或同步失败时保持 fail-open；`DEVIN_CONNECT` 使用独立 selector catalog | | `LS_BINARY_PATH` | `/opt/windsurf/language_server_linux_x64` | LS 二进制位置 | | `LS_DATA_DIR` | Linux: `/opt/windsurf/data`；macOS: `~/.windsurf/data` | 每个 proxy 独立的 LS 数据根目录 | diff --git a/src/devin-connect-openai.js b/src/devin-connect-openai.js index 3ea0e56c..f911f772 100644 --- a/src/devin-connect-openai.js +++ b/src/devin-connect-openai.js @@ -21,6 +21,7 @@ import { randomUUID } from 'crypto'; import { streamChat as realStreamChat, isRetryable, messageText } from './devin-connect.js'; import { ToolCallStreamParser, parseToolCallsFromText, isWeakEmulationModel } from './handlers/tool-emulation.js'; import { log } from './config.js'; +import { leakTraceEnabled, thinkMarkersIn, leakSample } from './leak-trace.js'; import { systemFingerprint } from './system-fingerprint.js'; import { applyStop, StopSequenceGate } from './stop-sequences.js'; import { normalizeToolCallArgs, recordArgRepair } from './handlers/cline-compat.js'; @@ -124,7 +125,7 @@ function isEmptyCompletion(finishEv, sawContent) { // guard aimed at it guards code that cannot be reached (the exact shape of the v3.9.13 medium // defect). If a caller ever genuinely needs to opt out, add the option back THEN, with a test // that passes `false` — that test is what makes it a knob rather than decoration. -async function* streamChatWithEmptyRetry(params, { env = process.env } = {}) { +async function* streamChatWithEmptyRetry(params, { env = process.env } = {}, opts = {}) { // Weak models (fable) return DETERMINISTIC empties on complex multi-turn / large // system — paid E2E (2026-07-08, 27/27) proved retry never heals them, it only // triples the upstream load and burns the account into a 3h rate limit. So for @@ -223,6 +224,16 @@ async function* streamChatWithEmptyRetry(params, { env = process.env } = {}) { sawReasoningText += ev.text; } } + if (leakTraceEnabled(env)) { + log.info('LEAK_TRACE stream-event', { + channel: ev.type, + think: thinkMarkersIn(ev.text), + sample: leakSample(ev.text), + len: ev.text ? ev.text.length : 0, + reqId: opts?.reqId ?? null, + account: opts?.account ?? null, + }); + } yield ev; } else if (ev.type === 'finish') { finishEv = ev; // hold: decide retry after the stream drains @@ -322,7 +333,8 @@ function nowSeconds() { * tool_calls (text-emulation, swe-1.6 etc). * @returns {Promise<{status:number, body:object}>} */ -export async function toChatCompletion(params, { id = newId(), created = nowSeconds(), displayModel, maxRetries = 2, retryBaseMs = 400, emulateTools = false, stop = null, clineCompat = false } = {}) { +export async function toChatCompletion(params, opts = {}) { + const { id = newId(), created = nowSeconds(), displayModel, maxRetries = 2, retryBaseMs = 400, emulateTools = false, stop = null, clineCompat = false } = opts; const model = displayModel || params.model; // Non-stream path buffers the whole answer, so a transient failure (network @@ -345,7 +357,7 @@ export async function toChatCompletion(params, { id = newId(), created = nowSeco for (let attempt = 0; ; attempt++) { try { content = ''; reasoning = ''; finishReason = 'stop'; usage = null; nativeToolCalls = []; - for await (const ev of streamChatWithEmptyRetry(params)) { + for await (const ev of streamChatWithEmptyRetry(params, undefined, opts)) { // A rescue attempt REPLACES the previous one; drop what it produced or the // client is handed every attempt concatenated. if (ev.type === 'attempt_reset') { content = ''; reasoning = ''; nativeToolCalls = []; billing = null; continue; } @@ -494,7 +506,8 @@ export async function toChatCompletion(params, { id = newId(), created = nowSeco * @returns {Promise<{content:string, reasoning:string, finish_reason:string, usage:object|null}>} * the assembled result, so callers can cache it after streaming. */ -export async function streamChatCompletion(params, send, { id = newId(), created = nowSeconds(), displayModel, emulateTools = false, includeUsage = false, stop = null, clineCompat = false } = {}) { +export async function streamChatCompletion(params, send, opts = {}) { + const { id = newId(), created = nowSeconds(), displayModel, emulateTools = false, includeUsage = false, stop = null, clineCompat = false } = opts; const model = displayModel || params.model; const base = { id, object: OBJECT_CHUNK, created, model, system_fingerprint: systemFingerprint(model) }; @@ -570,7 +583,7 @@ export async function streamChatCompletion(params, send, { id = newId(), created } }; - for await (const ev of streamChatWithEmptyRetry(params)) { + for await (const ev of streamChatWithEmptyRetry(params, undefined, opts)) { // A rescue attempt REPLACES the previous one. The deltas already sent cannot be // retracted (documented at the promotion site below), but the accumulators must // not keep the abandoned attempt — otherwise `content` ends up holding every diff --git a/src/handlers/chat.js b/src/handlers/chat.js index d02707ad..2b7e1096 100644 --- a/src/handlers/chat.js +++ b/src/handlers/chat.js @@ -10,6 +10,7 @@ import { isStickyEnabled, setStickyBinding, peekStickyBinding } from '../account import { resolveModel, getModelInfo, pickRateLimitFallback } from '../models.js'; import { getLsFor, ensureLs } from '../langserver.js'; import { config, log } from '../config.js'; +import { leakTraceEnabled, thinkMarkersIn, leakSample } from '../leak-trace.js'; import { safeAccountRef, safeKeyRef, safeLogValue } from '../log-safety.js'; import { recordRequest, recordTokenUsage, recordPolicyBlocked, recordRateLimited } from '../dashboard/stats.js'; import { extractIntentFromNarrative, detectToolIntentInNarrative } from './intent-extractor.js'; @@ -3131,7 +3132,7 @@ async function _handleChatCompletionsInner(body, context = {}) { const connectDisplayModel = mapped ? reqModelName : connectParams.model; // O1: honor stream_options.include_usage on the connect path too — the // trailing usage frame is emitted only when the caller opted in. - const connectMeta = { id: ccId, created: ccCreated, displayModel: connectDisplayModel, emulateTools, includeUsage: body.stream_options?.include_usage === true, stop: body.stop ?? null, clineCompat: clineCompatActive }; + const connectMeta = { id: ccId, created: ccCreated, displayModel: connectDisplayModel, emulateTools, includeUsage: body.stream_options?.include_usage === true, stop: body.stop ?? null, clineCompat: clineCompatActive, reqId, account: ccAcct ? safeAccountRef(ccAcct) : null }; // Shared failover bookkeeping for both stream + non-stream paths. triedKeys // accumulates every session token burned this request so getApiKey never // re-picks a known-dead account when we hop to the next pool member. @@ -3325,6 +3326,7 @@ async function _handleChatCompletionsInner(body, context = {}) { }; try { let acct = ccAcct; + let lastOkSr = null; for (let hops = 0; ; hops++) { // Client gone (disconnect or shutdown abort): stop before touching // another pooled account. Without this the failover loop keeps @@ -3353,6 +3355,7 @@ async function _handleChatCompletionsInner(body, context = {}) { if (acct) triedKeys.push(acct.apiKey); const r = await attemptStream(acct); if (r.kind === 'ok') { + lastOkSr = r.sr; // Pin this conversation to the account that just served it, so the // next turn reads the prompt cache back instead of re-writing it. // Complementary to the pair-chain commit below: that keeps the @@ -3418,6 +3421,19 @@ async function _handleChatCompletionsInner(body, context = {}) { bumpConnect('failover_hops'); acct = next; } + if (leakTraceEnabled()) { + log.info('LEAK_TRACE settle', { + reqId, + model: connectDisplayModel, + provider: null, + contentChars: (lastOkSr?.content ?? '').length, + reasoningChars: (lastOkSr?.reasoning ?? '').length, + rerouted: false, + thinkInContent: thinkMarkersIn(lastOkSr?.content), + sample: leakSample(lastOkSr?.content), + durationMs: Date.now() - ccStart, + }); + } // If the client already disconnected, don't try to write to a dead // socket — that can leave the handler stuck on a closed connection. if (!abortController.signal.aborted && !res.writableEnded) { res.write('data: [DONE]\n\n'); res.end(); } @@ -5846,19 +5862,34 @@ function streamResponse(id, created, model, modelKey, provider, messages, cascad // `modelKey` param (caller passes routingModelKey there); // wantThinking comes through deps because body isn't in // scope here (#93 follow-up zhangzhang-bit). - if (shouldFallbackThinkingToText({ + const thinkingPromotedToText = shouldFallbackThinkingToText({ routingModelKey: modelKey, wantThinking: deps.wantThinking, accText, accThinking, hasToolCalls: collectedToolCalls.length > 0, - })) { + }); + if (thinkingPromotedToText) { log.info(`Chat[${reqId}]: thinking-only stream from non-reasoning model ${modelKey}; promoting ${accThinking.length}c thinking → content`); send({ id, object: 'chat.completion.chunk', created, model, choices: [{ index: 0, delta: { content: accThinking }, finish_reason: null }] }); accText = accThinking; accThinking = ''; } + if (leakTraceEnabled()) { + log.info('LEAK_TRACE settle', { + reqId, + model, + modelKey, + provider, + contentChars: accText.length, + reasoningChars: accThinking.length, + rerouted: thinkingPromotedToText, + thinkInContent: thinkMarkersIn(accText), + sample: leakSample(accText), + durationMs: Date.now() - startTime, + }); + } const finalReason = collectedToolCalls.length ? 'tool_calls' : 'stop'; // OpenAI spec: the finish_reason chunk carries NO usage, then a // separate terminal chunk has empty choices[] + usage diff --git a/src/handlers/messages.js b/src/handlers/messages.js index c08ad42a..f7c5f3b1 100644 --- a/src/handlers/messages.js +++ b/src/handlers/messages.js @@ -14,6 +14,7 @@ import { createHash, randomUUID } from 'crypto'; import { handleChatCompletions, connectErrorToHttp } from './chat.js'; import { log } from '../config.js'; +import { leakTraceEnabled, thinkMarkersIn, leakSample } from '../leak-trace.js'; function genMsgId() { return 'msg_' + randomUUID().replace(/-/g, '').slice(0, 24); @@ -940,10 +941,14 @@ function buildAnthropicUsage(usage, cachePolicy = null) { // ─── Streaming translator: intercepts OpenAI SSE, emits Anthropic SSE ── class AnthropicStreamTranslator { - constructor(res, msgId, model, cachePolicy = null, inputEstimate = 0, stopSequences = null) { + constructor(res, msgId, model, cachePolicy = null, inputEstimate = 0, stopSequences = null, reqId = null, conversationId = null) { this.res = res; this.msgId = msgId; this.model = model; + // Stage E leak-trace identifiers (WINDSURFAPI_LEAK_TRACE): null unless the + // caller threads them in — log fields only, no behavior. + this.reqId = reqId; + this.conversationId = conversationId; // Local cache-prefix estimate from extractCachePolicy; used by finish() to // fill cache_creation_input_tokens when upstream reports none (see // buildAnthropicUsage). null when the request had no cache_control markers. @@ -1052,6 +1057,16 @@ class AnthropicStreamTranslator { index: this.blockIndex, content_block, }); + if (leakTraceEnabled()) { + log.info('LEAK_TRACE block-start', { + blockType: type, + channel: type === 'thinking' ? 'reasoning' : 'content', + msgId: this.msgId, + reqId: this.reqId, + conversationId: this.conversationId, + model: this.model, + }); + } } closeCurrentBlock() { @@ -1191,12 +1206,42 @@ class AnthropicStreamTranslator { const choice = chunk.choices?.[0]; if (choice) { const delta = choice.delta || {}; - if (delta.reasoning_content) this.emitThinkingDelta(delta.reasoning_content); + if (delta.reasoning_content) { + if (leakTraceEnabled()) { + log.info('LEAK_TRACE classify', { + channel: 'reasoning', + blockType: this.current?.type ?? null, + think: thinkMarkersIn(delta.reasoning_content), + sample: leakSample(delta.reasoning_content), + len: delta.reasoning_content.length, + msgId: this.msgId, + reqId: this.reqId, + conversationId: this.conversationId, + model: this.model, + }); + } + this.emitThinkingDelta(delta.reasoning_content); + } // Forward-compat: if a future upstream attaches a real encrypted signature // to the reasoning stream, capture it so closeCurrentBlock round-trips the // genuine value instead of the empty-string placeholder. if (delta.reasoning_signature) this.pendingThinkingSignature = delta.reasoning_signature; - if (delta.content) this.emitTextDelta(delta.content); + if (delta.content) { + if (leakTraceEnabled()) { + log.info('LEAK_TRACE classify', { + channel: 'content', + blockType: this.current?.type ?? null, + think: thinkMarkersIn(delta.content), + sample: leakSample(delta.content), + len: delta.content.length, + msgId: this.msgId, + reqId: this.reqId, + conversationId: this.conversationId, + model: this.model, + }); + } + this.emitTextDelta(delta.content); + } if (Array.isArray(delta.tool_calls)) { for (const tc of delta.tool_calls) this.emitToolCallDelta(tc); } @@ -1528,7 +1573,7 @@ export async function handleMessages(body, context = {}) { 'X-Accel-Buffering': 'no', }, async handler(realRes) { - const translator = new AnthropicStreamTranslator(realRes, msgId, requestedModel, cachePolicy, inputEstimate, body.stop_sequences); + const translator = new AnthropicStreamTranslator(realRes, msgId, requestedModel, cachePolicy, inputEstimate, body.stop_sequences, context.reqId, context.conversation_id); const captureRes = createCaptureRes(translator, realRes); // Forward client disconnect so the upstream cascade is cancelled. diff --git a/src/leak-trace.js b/src/leak-trace.js new file mode 100644 index 00000000..5ff1734b --- /dev/null +++ b/src/leak-trace.js @@ -0,0 +1,40 @@ +// Reasoning/content boundary tracing — gate-controlled OBSERVABILITY. +// +// WINDSURFAPI_LEAK_TRACE=1 emits structured log lines at the reasoning/content +// boundary so the live-only leak — model reasoning spilling into the content +// channel (PRs #238/#241/#243 rescued empty answers and rerouted a ' thinking' +// prefix, but never reproduced the leak in a forced harness) — can be caught in +// production. Default OFF: when disabled the hot path does nothing beyond one +// env read + boolean compare and nothing else changes. +// +// Every line is prefixed `LEAK_TRACE` and carries structured fields. The three +// call sites: +// - devin-connect-openai.js streamChatWithEmptyRetry: per raw stream event — +// channel (content/reasoning), think markers, truncated sample. +// - handlers/messages.js AnthropicStreamTranslator: block open + per-delta +// classification (blockType/channel). +// - handlers/chat.js streamResponse: settle summary — what went to content vs +// reasoning and whether the thinking→content fallback fired. +import { safeLogValue } from './log-safety.js'; + +export const LEAK_TRACE_ENV = 'WINDSURFAPI_LEAK_TRACE'; + +export function leakTraceEnabled(env = process.env) { + return String(env[LEAK_TRACE_ENV] ?? '').trim() === '1'; +} + +// Marker strings that indicate model reasoning present in a text channel. +// DeepSeek wraps reasoning in …; Kimi K2 emits ◁think▷. +// Extend here when another model ships a different marker. +export const THINK_MARKERS = ['', '', '◁think▷']; + +export function thinkMarkersIn(text) { + const found = THINK_MARKERS.filter((m) => String(text ?? '').includes(m)); + return found.length ? found : null; +} + +// Bounded text sample for logs (never the whole payload). Reuses the repo's +// existing log-boundary sanitizer (control chars → '·', slice to max, '…'). +export function leakSample(text, max = 120) { + return safeLogValue(text, max); +} diff --git a/test/leak-trace.test.js b/test/leak-trace.test.js new file mode 100644 index 00000000..11c2e112 --- /dev/null +++ b/test/leak-trace.test.js @@ -0,0 +1,158 @@ +// Stage E: WINDSURFAPI_LEAK_TRACE — structured reasoning/content boundary logs. +// +// The gate is read per call (leakTraceEnabled()), so a single file toggles +// process.env.WINDSURFAPI_LEAK_TRACE between tests. Logger stub style follows +// test/retry-rescue-budget-split.test.js (message-first variadic log), except +// the fields object is JSON-stringified so field-level assertions work (the +// repo sample flattens objects to '[object Object]'). +import { afterEach, beforeEach, it } from 'node:test'; +import assert from 'node:assert/strict'; +import { addAccountByKey, removeAccount } from '../src/auth.js'; +import { log } from '../src/config.js'; +import { handleChatCompletions, __resetConnectDeps, __setConnectDeps } from '../src/handlers/chat.js'; +import { handleMessages } from '../src/handlers/messages.js'; +import { toChatCompletion, __setStreamChatForTest } from '../src/devin-connect-openai.js'; + +let captured = []; +const originalInfo = log.info; +const originalWarn = log.warn; + +function captureLogs() { + captured = []; + log.info = (...args) => captured.push(args.map((a) => (typeof a === 'string' ? a : JSON.stringify(a))).join(' ')); + log.warn = (...args) => captured.push(args.map((a) => (typeof a === 'string' ? a : JSON.stringify(a))).join(' ')); +} +const leakLines = () => captured.filter((l) => l.includes('LEAK_TRACE')); +const sseFrame = (obj) => `data: ${JSON.stringify(obj)}\n\n`; + +function fakeStreamRes() { + const listeners = new Map(); + return { + body: '', writableEnded: false, + write(chunk) { this.body += String(chunk); return true; }, + end(chunk) { + if (chunk) this.write(chunk); + this.writableEnded = true; + for (const cb of listeners.get('close') || []) cb(); + }, + on(event, cb) { + if (!listeners.has(event)) listeners.set(event, []); + listeners.get(event).push(cb); + return this; + }, + }; +} + +beforeEach(() => { + __resetConnectDeps(); + __setStreamChatForTest(null); + captureLogs(); +}); + +afterEach(() => { + log.info = originalInfo; + log.warn = originalWarn; + __resetConnectDeps(); + __setStreamChatForTest(null); + delete process.env.WINDSURFAPI_LEAK_TRACE; + delete process.env.DEVIN_CONNECT; + delete process.env.DEVIN_CONNECT_RETRY_ON_EMPTY_MS; +}); + +// --- devin-connect-openai.js: raw stream events at the channel boundary --- + +it('gate ON: raw stream events logged with channel/think/sample/reqId/account', async () => { + process.env.WINDSURFAPI_LEAK_TRACE = '1'; + process.env.DEVIN_CONNECT_RETRY_ON_EMPTY_MS = '0'; + __setStreamChatForTest(async function* () { + yield { type: 'reasoning', text: 'let me think ' }; + yield { type: 'content', text: 'x'.repeat(500) }; + yield { type: 'finish', reason: 'stop' }; + }); + const out = await toChatCompletion({ model: 'm' }, { reqId: 'r1', account: 'acc-1' }); + assert.equal(out.body.choices[0].message.content, 'x'.repeat(500)); + const lines = leakLines(); + assert.equal(lines.length, 2, 'one stream-event line per text-bearing event'); + const reasoning = lines.find((l) => l.includes('"channel":"reasoning"')); + const content = lines.find((l) => l.includes('"channel":"content"')); + assert.ok(reasoning, 'reasoning event logged'); + assert.ok(content, 'content event logged'); + assert.ok(reasoning.includes('LEAK_TRACE stream-event'), 'message prefix'); + assert.ok(reasoning.includes('"think":[""]'), 'think marker detected'); + assert.ok(content.includes('"len":500'), 'len field'); + assert.ok(content.includes('"sample":"') && content.includes('…'), 'sample truncated'); + assert.ok(content.includes('"reqId":"r1"') && content.includes('"account":"acc-1"'), 'reqId/account threaded via opts'); +}); + +it('gate OFF: zero LEAK_TRACE lines on the same hot path', async () => { + delete process.env.WINDSURFAPI_LEAK_TRACE; + process.env.DEVIN_CONNECT_RETRY_ON_EMPTY_MS = '0'; + __setStreamChatForTest(async function* () { + yield { type: 'reasoning', text: 'think hard' }; + yield { type: 'content', text: 'answer' }; + yield { type: 'finish', reason: 'stop' }; + }); + await toChatCompletion({ model: 'm' }, { reqId: 'r1', account: 'acc-1' }); + assert.equal(leakLines().length, 0, 'no leak-trace lines when WINDSURFAPI_LEAK_TRACE is off'); +}); + +// --- messages.js: block classification / rerouting decisions --- + +it('gate ON: messages.js classify + block-start logs with channel/reqId fields', async () => { + process.env.WINDSURFAPI_LEAK_TRACE = '1'; + const fakeUpstream = async (body, ctx) => ({ + status: 200, + stream: true, + handler: async (captureRes) => { + captureRes.write(sseFrame({ choices: [{ delta: { role: 'assistant' } }] })); + captureRes.write(sseFrame({ choices: [{ delta: { reasoning_content: 'deep think ' } }] })); + captureRes.write(sseFrame({ choices: [{ delta: { content: 'hi there' } }] })); + captureRes.write(sseFrame({ choices: [{ delta: {}, finish_reason: 'stop' }] })); + captureRes.write('data: [DONE]\n\n'); + }, + }); + const result = await handleMessages( + { model: 'm', stream: true, messages: [{ role: 'user', content: 'q' }], max_tokens: 10 }, + { handleChatCompletions: fakeUpstream, reqId: 'r1', conversation_id: 'c1' }, + ); + const res = fakeStreamRes(); + await result.handler(res); + const lines = leakLines(); + assert.ok(lines.some((l) => l.includes('LEAK_TRACE classify') && l.includes('"channel":"reasoning"')), 'reasoning classification logged'); + assert.ok(lines.some((l) => l.includes('LEAK_TRACE classify') && l.includes('"channel":"content"')), 'content classification logged'); + assert.ok(lines.some((l) => l.includes('LEAK_TRACE block-start')), 'block-start logged'); + assert.ok(lines.some((l) => l.includes('"reqId":"r1"')), 'reqId threaded into translator'); + assert.ok(lines.some((l) => l.includes('"think":[""]')), 'think marker in reasoning sample'); +}); + +// --- chat.js: settle summary (what went to content vs reasoning) --- + +it('gate ON: chat.js streamResponse settle log with content/reasoning sizes', async () => { + process.env.WINDSURFAPI_LEAK_TRACE = '1'; + process.env.DEVIN_CONNECT = '1'; + const key = `leak-trace-token-${Math.random().toString(36).slice(2)}`; + const acct = addAccountByKey(key, 'leak-trace'); + try { + __setConnectDeps({ + streamChatCompletion: async (params, send) => { + send({ id: 'c1', object: 'chat.completion.chunk', created: 1, model: params.model, choices: [{ index: 0, delta: { reasoning_content: 'deep reasoning' }, finish_reason: null }] }); + send({ id: 'c1', object: 'chat.completion.chunk', created: 1, model: params.model, choices: [{ index: 0, delta: { content: 'hello world' }, finish_reason: null }] }); + return { id: 'c1', object: 'chat.completion.chunk', created: 1, model: params.model, content: 'hello world', reasoning: 'deep reasoning', finish_reason: 'stop', usage: { total_tokens: 9 }, billing: {} }; + }, + }); + const result = await handleChatCompletions( + { model: 'swe-1-6-slow', stream: true, messages: [{ role: 'user', content: 'hi' }] }, + { callerKey: '' }, + ); + const res = fakeStreamRes(); + await result.handler(res); + const settle = leakLines().find((l) => l.includes('LEAK_TRACE settle')); + assert.ok(settle, 'settle log present'); + assert.ok(settle.includes('"contentChars":11'), `content size 11 (hello world), got: ${settle}`); + assert.ok(settle.includes('"reasoningChars":14'), `reasoning size 14 (deep reasoning), got: ${settle}`); + assert.ok(settle.includes('"rerouted":false'), 'reroute flag false'); + assert.ok(settle.includes('"reqId":'), 'reqId in settle fields'); + } finally { + removeAccount(acct.id); + } +}); diff --git a/test/mutations/leak-trace.json b/test/mutations/leak-trace.json new file mode 100644 index 00000000..89a96571 --- /dev/null +++ b/test/mutations/leak-trace.json @@ -0,0 +1,48 @@ +{ + "tests": ["test/leak-trace.test.js"], + "expectBaselinePass": 4, + "mutations": [ + { + "name": "gate inverted — tracing never fires", + "file": "src/leak-trace.js", + "anchor": " return String(env[LEAK_TRACE_ENV] ?? '').trim() === '1';", + "replacement": " return String(env[LEAK_TRACE_ENV] ?? '').trim() === '0';", + "expectCaught": true + }, + { + "name": "gate removed — tracing always on", + "file": "src/leak-trace.js", + "anchor": " return String(env[LEAK_TRACE_ENV] ?? '').trim() === '1';", + "replacement": " return true;", + "expectCaught": true + }, + { + "name": "think-marker detection neutered", + "file": "src/leak-trace.js", + "anchor": " return found.length ? found : null;", + "replacement": " return null;", + "expectCaught": true + }, + { + "name": "stream-event channel field dropped", + "file": "src/devin-connect-openai.js", + "anchor": " channel: ev.type,", + "replacement": " channelKind: ev.type,", + "expectCaught": true + }, + { + "name": "classify log demoted to debug", + "file": "src/handlers/messages.js", + "anchor": " log.info('LEAK_TRACE classify', {\n channel: 'reasoning',", + "replacement": " log.debug('LEAK_TRACE classify', {\n channel: 'reasoning',", + "expectCaught": true + }, + { + "name": "settle log demoted to debug", + "file": "src/handlers/chat.js", + "anchor": " log.info('LEAK_TRACE settle', {\n reqId,\n model: connectDisplayModel,", + "replacement": " log.debug('LEAK_TRACE settle', {", + "expectCaught": true + } + ] +}