zhaoshang_client_ui/harness/tools/probe-answer-tail-timing.mjs

/**
 * 量「正文结束 → 参考资料出现」这段**收尾等待**到底花在哪。
 *
 * 背景：正文是逐片流式上屏的，但参考资料（`<ref_links>`）要等 `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('<ref_links>')) 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`);
}