Issue: 供应商故障转移后出现延迟的 499 错误

[RWDai]

为什么 499 能到 59 秒？我设置了 20 秒首字超时的

Originally posted by @RWDai in #229

📋 问题描述

当供应商首字节超时触发故障转移后，约 60 秒后会在日志中出现误导性的 499 错误（"Response transmission aborted"）。虽然此错误不影响实际业务（请求已成功通过第二个供应商完成），但会造成日志污染、资源浪费和潜在的连接池耗尽风险。

🔍 问题现象

症状

• 故障转移成功，客户端正常收到响应
• 约 60 秒后，日志中出现 ProxyError: Response transmission aborted (状态码 499)
• 错误来源于已被中止的第一个供应商的延迟清理

日志证据

2025-12-06T16:35:34.393Z - 请求开始，选择供应商 xyai-2025/12/8 16:11:34 (ID=2)
2025-12-06T16:35:38.588Z - [WARN] ProxyForwarder: Response timeout (首字节超时 20s)
2025-12-06T16:35:38.589Z - [ERROR] ProxyForwarder: Response timeout (provider quality issue, will switch)
2025-12-06T16:35:38.594Z - [INFO] ProxyForwarder: Switched to alternative provider (WONG, ID=7)
2025-12-06T16:35:42.991Z - [INFO] ProxyForwarder: Request successful (第二个供应商成功)
2025-12-06T16:35:45.496Z - [DEBUG] Task completed successfully (响应完整传输)

⚠️ 约 60 秒后：
2025-12-06T16:36:34.368Z - [WARN] ProxyForwarder: Request/response aborted
2025-12-06T16:36:34.368Z - [ERROR] Proxy handler error: "Response transmission aborted" (statusCode=499)

时间线分析

时间偏移	事件	说明
T+0s (16:35:34)	请求开始	选择第一个供应商 xyai
T+4s (16:35:38)	首字节超时	responseController.abort() 被调用
T+4s (16:35:38)	故障转移	立即切换到第二个供应商 WONG
T+8s (16:35:42)	获取响应头	第二个供应商成功响应
T+11s (16:35:45)	响应完成	客户端收到完整数据
T+60s (16:36:34)	延迟错误	第一个供应商的连接终于被清理，抛出 499 错误

🔧 根因分析

问题定位

在 src/app/v1/_lib/proxy/forwarder.ts 中：

1. 超时触发位置 (行 932-942)

   if (responseTimeoutMs > 0) {
     responseTimeoutId = setTimeout(() => {
       responseController.abort(); // ⚠️ 只中止 fetch，但底层 TCP 连接未立即清理
       logger.warn("ProxyForwarder: Response timeout", {
         providerId: provider.id,
         providerName: provider.name,
         responseTimeoutMs,
         responseTimeoutType,
         isStreaming,
       });
     }, responseTimeoutMs);
   }

2. 延迟错误捕获位置 (行 1162-1179)

   if (isClientAbortError(err)) {
     logger.warn("ProxyForwarder: Request/response aborted", {
       providerId: provider.id,
       providerName: provider.name,
       proxyUrl: new URL(proxyUrl).origin,
       errorName: err.name,
       errorMessage: err.message || "(empty message)",
       errorCode: err.code || "N/A",
     });
   
     throw new ProxyError(
       err.name === "ResponseAborted"
         ? "Response transmission aborted" // ⚠️ 误导性错误消息
         : "Request aborted by client",
       499
     );
   }

技术原因

这是 undici fetch 实现的异步清理延迟问题：

1. AbortController 行为

   • responseController.abort() 会立即中止 fetch 操作
   • 抛出 ProxyError (524) 并触发故障转移
   • 但底层的 HTTP 连接（TCP/TLS）并未立即关闭

2. 连接池保持

   • undici 的 Agent 连接池保留了第一个供应商的连接
   • 这个连接仍在等待服务器响应或超时
   • 约 60 秒后（可能是 TCP keepalive 或服务器超时），连接终于被清理

3. 孤儿错误

   • 当底层连接最终关闭时，触发 ResponseAborted 错误
   • 此时请求已完成，这个错误成为"孤儿"
   • 被错误地归类为客户端中止 (499)

📊 影响范围

严重程度：中等 (Medium)

功能影响

• ✅ 不影响业务功能：故障转移正常工作，客户端正常收到响应
• ❌ 日志污染：产生误导性的 499 错误，干扰监控和告警
• ❌ 资源浪费：第一个供应商的连接挂起约 60 秒才被清理

潜在风险

1. 连接池耗尽：高频故障转移场景下，可能耗尽 undici 连接池
2. 监控误判：499 错误可能触发不必要的告警
3. 排查困难：日志中的 499 错误与实际客户端中断混淆

触发条件

• 供应商首字节超时 (firstByteTimeoutStreamingMs 或 requestTimeoutNonStreamingMs)
• 成功故障转移到备用供应商
• 第一个供应商的连接保持活跃约 60 秒

💡 建议的解决方案

方案 1: 显式清理 Agent 连接 ⭐ (推荐)

优点: 彻底解决问题，立即释放资源
缺点: 需要修改 forwarder 逻辑

实现思路:

// 在 forwarder.ts 中记录 agent 引用
const agentToCleanup = proxyConfig?.agent || (init.dispatcher as Agent);

responseTimeoutId = setTimeout(() => {
  responseController.abort();

  // 主动销毁底层连接
  if (agentToCleanup && 'destroy' in agentToCleanup) {
    try {
      (agentToCleanup as Agent).destroy();
      logger.debug("ProxyForwarder: Agent destroyed on timeout", {
        providerId: provider.id,
      });
    } catch (err) {
      logger.warn("ProxyForwarder: Failed to destroy agent", { err });
    }
  }

  logger.warn("ProxyForwarder: Response timeout and connection cleaned", {
    providerId: provider.id,
    providerName: provider.name,
    responseTimeoutMs,
    responseTimeoutType,
    isStreaming,
  });
}, responseTimeoutMs);

修改位置: src/app/v1/_lib/proxy/forwarder.ts:932-942

---

方案 2: 识别并忽略孤儿错误

优点: 最小化代码修改
缺点: 治标不治本，连接仍会挂起 60 秒

实现思路:

// 在 forwarder.ts 中记录成功时间
let lastSuccessTime: number | null = null;

// 成功时记录
if (response) {
  lastSuccessTime = Date.now();
}

// 错误处理时检测
if (isClientAbortError(err)) {
  // 检查是否是延迟的清理错误（请求已完成 > 5 秒）
  if (err.name === "ResponseAborted" && lastSuccessTime &&
      (Date.now() - lastSuccessTime > 5000)) {
    logger.debug("ProxyForwarder: Ignoring delayed connection cleanup", {
      providerId: provider.id,
      timeSinceSuccess: Date.now() - lastSuccessTime,
    });
    return; // 静默忽略，不抛出 499 错误
  }

  // 真正的客户端中断才抛出错误
  throw new ProxyError(
    err.name === "ResponseAborted"
      ? "Response transmission aborted"
      : "Request aborted by client",
    499
  );
}

修改位置: src/app/v1/_lib/proxy/forwarder.ts:1162-1179

---

方案 3: 调整超时配置 (临时缓解)

优点: 无需代码修改
缺点: 只能减少触发频率，不能解决根本问题

配置调整:

# 增加首字节超时时间（从 20s 提高到 30s）
FIRST_BYTE_TIMEOUT_STREAMING_MS=30000

# 或者在供应商管理页面单独配置慢速供应商的超时

🧪 复现步骤

1. 配置两个供应商，第一个供应商设置较短的首字节超时（如 20 秒）
2. 确保第一个供应商响应缓慢（真实超时或人为延迟）
3. 发送流式请求（如 Claude messages API）
4. 观察日志：
   • T+20s: 首字节超时，故障转移
   • T+25s: 第二个供应商成功响应
   • T+80s: 出现 499 错误

📝 环境信息

• 部署方式: Docker Compose
• Claude Code Hub 版本: (请提供 git commit hash 或 release tag)
• Node.js 版本: 20+ (Docker 镜像内)
• undici 版本: (Next.js 15 内置)
• 相关配置:
  • firstByteTimeoutStreamingMs: 20000 (20秒)
  • ENABLE_CIRCUIT_BREAKER_ON_NETWORK_ERRORS: false
  • MAX_RETRY_ATTEMPTS_DEFAULT: 2

🔗 相关文件

• src/app/v1/_lib/proxy/forwarder.ts (核心问题代码)
• src/app/v1/_lib/proxy/errors.ts (错误分类逻辑)
• src/lib/proxy-agent.ts (代理 Agent 创建)

✅ 验收标准

1. 供应商超时触发故障转移后，不再出现延迟的 499 错误
2. 第一个供应商的连接在超时后立即被清理（或在 5 秒内）
3. 日志中的 499 错误仅表示真正的客户端中断
4. 不影响现有的故障转移和熔断器功能

🏷️ 标签建议

• bug - 代码缺陷
• priority: medium - 中等优先级
• area: proxy - 代理转发模块
• good first issue (如果选择方案 2 或 3)

[github-actions]

感谢您提交的详细问题报告！这是一个非常有价值的发现。

🔍 问题分析

您的分析完全正确。这是一个 undici fetch 实现的异步清理延迟问题：

当首字节超时触发 responseController.abort() 后，虽然 fetch 操作立即中止并触发故障转移，但底层的 TCP/TLS 连接并未立即关闭。undici 的连接池仍保留该连接，直到约 60 秒后（可能是 TCP keepalive 或服务器超时）才完成清理，此时抛出的 ResponseAborted 错误成为"孤儿错误"，被误判为客户端中断（499）。

影响评估：

• ✅ 不影响业务功能（故障转移正常工作）
• ❌ 日志污染（产生误导性的 499 错误）
• ❌ 资源浪费（连接挂起约 60 秒）
• ⚠️ 高频故障转移场景可能耗尽连接池

💡 解决方案建议

您提出的三个方案都很有价值，我的建议是：

推荐方案：方案 1（显式清理 Agent 连接） + 方案 2（识别孤儿错误） 组合使用

理由：

1. 方案 1 治本：在超时时主动销毁 Agent，立即释放底层连接
2. 方案 2 容错：即使清理失败，也能识别并忽略延迟的孤儿错误
3. 两者结合可以最大程度避免日志污染和资源浪费

实现建议

在 src/app/v1/_lib/proxy/forwarder.ts 中：

1. 超时处理增加 Agent 清理（约 932-942 行）：

responseTimeoutId = setTimeout(() => {
  responseController.abort();
  
  // 主动清理底层连接
  if (proxyConfig?.agent && 'destroy' in proxyConfig.agent) {
    try {
      (proxyConfig.agent as Agent).destroy();
      logger.debug("ProxyForwarder: Agent destroyed on timeout", {
        providerId: provider.id,
      });
    } catch (err) {
      logger.warn("ProxyForwarder: Failed to destroy agent", { err });
    }
  }
  
  logger.warn("ProxyForwarder: Response timeout", {
    providerId: provider.id,
    providerName: provider.name,
    responseTimeoutMs,
    responseTimeoutType,
    isStreaming,
  });
}, responseTimeoutMs);

2. 错误处理增加孤儿检测（约 1162-1179 行）：

if (isClientAbortError(err)) {
  // 检查是否是延迟的清理错误（请求已成功完成）
  const timeSinceSuccess = lastSuccessTime ? Date.now() - lastSuccessTime : -1;
  if (err.name === "ResponseAborted" && timeSinceSuccess > 5000) {
    logger.debug("ProxyForwarder: Ignoring delayed connection cleanup", {
      providerId: provider.id,
      timeSinceSuccess,
    });
    return; // 静默忽略
  }

  logger.warn("ProxyForwarder: Request/response aborted", {
    providerId: provider.id,
    providerName: provider.name,
    proxyUrl: new URL(proxyUrl).origin,
    errorName: err.name,
    errorMessage: err.message || "(empty message)",
    errorCode: err.code || "N/A",
  });

  throw new ProxyError(
    err.name === "ResponseAborted"
      ? "Response transmission aborted"
      : "Request aborted by client",
    499
  );
}

🔄 下一步

如果您同意这个方案，请回复 @claude please fix this，我将创建 PR 来实现这个修复。

如果您希望讨论其他实现方式或有任何疑问，请随时回复！

---

🤖 This is an automated response from Claude AI