/** * 量「正文结束 → 参考资料出现」这段**收尾等待**到底花在哪。 * * 背景:正文是逐片流式上屏的,但参考资料(``)要等 `done` 才由 `flushContent` * 追加。用户反馈正文结束后还要等 1~2 秒才看到参考资料 —— 这个脚本就是量这段。 * * 它**增量读 SSE**(不是 `await res.text()` 攒完再解析),所以能拿到每个事件真正的到达时刻。 * * 怎么跑(需要 dev server 起着走同源代理): * node harness/tools/probe-answer-tail-timing.mjs "青浦区高新技术企业有什么扶持政策" * # 可选:CHAT_BASE=https://localhost:8083/chat-api 覆盖地址 * * 只读:不改任何数据。 */ process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0'; const chatBase = (process.env.CHAT_BASE || 'https://localhost:8083/chat-api').replace(/\/+$/, ''); const question = process.argv[2] || '青浦区高新技术企业有什么扶持政策'; const startedAt = Date.now(); const res = await fetch(`${chatBase}/api/chat`, { method: 'POST', headers: { 'Content-Type': 'application/json' }, body: JSON.stringify({ thread_id: `probe-tail-${Date.now()}`, question }), }); if (!res.ok) { console.error(`HTTP ${res.status}`); process.exit(1); } console.log(`问题:${question}\n地址:${chatBase}/api/chat\n`); const reader = res.body.getReader(); const decoder = new TextDecoder(); let buffer = ''; const events = []; // { name, at, size } /** 原始事件块 + 到达时刻 —— 回放时按同样的节奏喂,才能量出「不动 done 能提前多久」 */ const blocks = []; const handleEvent = (block) => { const m = block.match(/^event: (\S+)\r?\ndata: ([\s\S]*)$/); if (!m) return; const at = Date.now() - startedAt; events.push({ name: m[1], at, size: m[2].length }); blocks.push({ text: `${block}\n\n`, at }); }; while (true) { const { value, done } = await reader.read(); if (done) break; buffer += decoder.decode(value, { stream: true }); let idx; while ((idx = buffer.search(/\r?\n\r?\n/)) !== -1) { const nl = buffer.match(/\r?\n\r?\n/)[0].length; handleEvent(buffer.slice(0, idx)); buffer = buffer.slice(idx + nl); } } if (buffer.trim()) handleEvent(buffer); const totalMs = Date.now() - startedAt; /* ---------------- 统计 ---------------- */ const first = (name) => events.find((e) => e.name === name); const last = (name) => [...events].reverse().find((e) => e.name === name); const count = (name) => events.filter((e) => e.name === name).length; const deltaLast = last('answer_delta'); const answerEnd = first('answer_end'); const summary = first('summary'); const result = first('result'); const done = first('done'); const refLinksInPayload = events.some( (e) => e.name === 'summary' || e.name === 'result' ); console.log('【事件计数】', JSON.stringify( events.reduce((acc, e) => ((acc[e.name] = (acc[e.name] || 0) + 1), acc), {}) )); console.log('\n【收尾时间线】(相对请求发出;括号内为距上一步的间隔)'); const steps = [ ['最后一片 source(参考资料的数据)', last('source')], ['最后一片 item(卡片数据)', last('item')], ['answer_start(正文开流)', first('answer_start')], ['最后一片 answer_delta', deltaLast], ['answer_end(正文定稿)', answerEnd], ['summary', summary], ['result', result], ['done', done], ].filter(([, e]) => e); let prev = null; for (const [label, e] of steps) { const gap = prev === null ? '' : ` (+${((e.at - prev.at) / 1000).toFixed(2)}s)`; console.log(` ${String(e.at / 1000).padStart(6)}s ${label}${gap}`); prev = e; } console.log(` ${String(totalMs / 1000).padStart(6)}s 流结束(EOF)`); console.log('\n【结论】'); const waitAfterBody = answerEnd ? (totalMs - answerEnd.at) / 1000 : null; console.log(` 正文定稿 → 流结束:${waitAfterBody === null ? '(无 answer_end)' : waitAfterBody.toFixed(2) + 's'}`); if (!done) { console.log(' ⚠️ 没有 done 事件 —— 前端会在 EOF 才 flush(把参考资料推到最后时刻),'); console.log(' 而且会走「断流」分支报 disconnected。这是**最大的等待来源**。'); } if (answerEnd && summary) { console.log(` answer_end → summary:${((summary.at - answerEnd.at) / 1000).toFixed(2)}s`); } if (summary && result) { console.log(` summary → result:${((result.at - summary.at) / 1000).toFixed(2)}s(result 是完整快照,通常最大)`); console.log(` result 载荷大小:${result.size} 字符`); } console.log(' 参考资料由 source 事件决定,而 source 在 answer_start 之前就发完了 ——'); console.log(' 也就是说「等参考资料」等的是 done,不是等数据。'); /* ------------------------------------------------------------------ * * ③ 按**原时间轴**回放给真实协调器:量「参考资料提前上屏」省了多久 * ------------------------------------------------------------------ */ console.log('\n【回放】按原时间轴喂真实协调器,看参考资料什么时候上屏'); const { ApiChatCoordinator } = await import('./_coordinator.mjs'); globalThis.fetch = async () => { const encoder = new TextEncoder(); return new Response( new ReadableStream({ async start(controller) { let elapsed = 0; for (const block of blocks) { const wait = Math.max(0, block.at - elapsed); if (wait) await new Promise((r) => setTimeout(r, wait)); elapsed = block.at; controller.enqueue(encoder.encode(block.text)); } controller.close(); }, }), { status: 200, headers: { 'Content-Type': 'text/event-stream' } } ); }; const replayStart = Date.now(); const coordinator = new ApiChatCoordinator({ chatBaseUrl: undefined, baseUrl: 'http://stub', threadId: 'replay' }); let refsAt = null; let doneAt = null; coordinator.addEventListener('message', (msg) => { if (refsAt === null && msg.includes('')) refsAt = Date.now() - replayStart; }); coordinator.addEventListener('totalResponse', () => { if (doneAt === null) doneAt = Date.now() - replayStart; }); await coordinator.generateAnswer(question); await new Promise((r) => setTimeout(r, 400)); if (refsAt !== null && doneAt !== null) { const savedMs = doneAt - refsAt; console.log(` 参考资料上屏:${(refsAt / 1000).toFixed(1)}s`); console.log(` 收尾完成(done):${(doneAt / 1000).toFixed(1)}s`); console.log(` → **提前了 ${(savedMs / 1000).toFixed(1)} 秒**(修前等于 done 时刻)`); } else { console.log(` ⚠️ 没测到:参考资料@${refsAt}ms 收尾@${doneAt}ms`); }