fix(stream): 修复流式请求超时和取消归因问题

- 流式请求 timeout 改为 None,避免 provider.request_timeout 作为整条流总时长超时导致长响应被硬切断
- 重构 CancelledError 断连归因逻辑:提取探测方法并支持多次重试确认,降低误判率
- 新增 cancelled_unknown 状态处理断连检测不确定的场景,避免错误归因为 server_cancelled
- 在 upstream_response 中记录取消详情,便于排查
- 新增断连归因逻辑的单元测试
This commit is contained in:
fawney19
2026-03-01 13:02:26 +08:00
parent dc2bc83c17
commit a66fa9792d
4 changed files with 185 additions and 22 deletions

View File

@@ -1143,11 +1143,11 @@ class ChatHandlerBase(BaseMessageHandler, ABC):
url=url, url=url,
headers=provider_headers, headers=provider_headers,
payload=provider_payload, payload=provider_payload,
timeout=( # 流式请求不应使用 provider.request_timeout 作为“整条流总时长”超时,
provider.request_timeout or config.http_request_timeout # 否则会在长响应中途被硬切断(常见于 request_timeout=15s 的配置)。
if delegate_cfg # 首字节超时由外层 wait_for(stream_first_byte_timeout) 控制;
else None # 后续分块读取由 http client 默认 read timeout长超时控制。
), timeout=None,
) )
response_ctx = http_client.stream(**_skw) response_ctx = http_client.stream(**_skw)
stream_response = await response_ctx.__aenter__() stream_response = await response_ctx.__aenter__()

View File

@@ -32,6 +32,67 @@ if TYPE_CHECKING:
class CliMonitorMixin: class CliMonitorMixin:
"""监控和统计相关方法的 Mixin""" """监控和统计相关方法的 Mixin"""
# CancelledError 归因时,断连检查参数(秒)
CANCEL_DISCONNECT_CHECK_TIMEOUT_SECONDS = 0.5
CANCEL_DISCONNECT_RETRY_DELAYS_SECONDS = (0.1, 0.2)
async def _probe_client_disconnect(
self,
http_request: Request,
*,
request_id: str,
) -> tuple[bool, bool]:
"""单次探测客户端是否断连。
Returns:
(is_disconnected, is_indeterminate)
"""
try:
disconnected = await asyncio.wait_for(
asyncio.shield(http_request.is_disconnected()),
timeout=self.CANCEL_DISCONNECT_CHECK_TIMEOUT_SECONDS,
)
return bool(disconnected), False
except (asyncio.CancelledError, asyncio.TimeoutError):
return False, True
except Exception as e:
logger.debug("ID:{} | cancel 断连检测失败: {}", request_id, e)
return False, True
async def _confirm_client_disconnect(
self,
http_request: Request,
*,
request_id: str,
) -> tuple[bool, bool]:
"""CancelledError 场景下做多次断连确认,降低误判。
Returns:
(is_client_disconnected, check_indeterminate)
"""
disconnected, uncertain = await self._probe_client_disconnect(
http_request,
request_id=request_id,
)
if disconnected:
return True, uncertain
for delay in self.CANCEL_DISCONNECT_RETRY_DELAYS_SECONDS:
try:
await asyncio.sleep(delay)
except asyncio.CancelledError:
# 重试期间协程再次被取消,无法继续探测,标记为不确定
return False, True
disconnected, step_uncertain = await self._probe_client_disconnect(
http_request,
request_id=request_id,
)
uncertain = uncertain or step_uncertain
if disconnected:
return True, uncertain
return False, uncertain
async def _create_monitored_stream( async def _create_monitored_stream(
self, self,
ctx: StreamContext, ctx: StreamContext,
@@ -111,26 +172,21 @@ class CliMonitorMixin:
time_since_last_chunk = time_module.time() - last_chunk_time time_since_last_chunk = time_module.time() - last_chunk_time
is_client_disconnected = False is_client_disconnected = False
disconnect_check_uncertain = False
if http_request is not None: if http_request is not None:
try: is_client_disconnected, disconnect_check_uncertain = (
# shield + timeout: 避免在取消态下二次被 CancelledError 打断,尽力取到断连状态 await self._confirm_client_disconnect(
# 限时 0.5s 防止极端情况下的阻塞 http_request,
is_client_disconnected = await asyncio.wait_for( request_id=ctx.request_id,
asyncio.shield(http_request.is_disconnected()), )
timeout=0.5,
) )
except (asyncio.CancelledError, asyncio.TimeoutError):
# 无法在取消态/超时下完成断连检查,保守视为未知(不强行归因为客户端)
is_client_disconnected = False
except Exception as e:
logger.debug("ID:{} | cancel 断连检测失败: {}", ctx.request_id, e)
is_client_disconnected = False
# 如果响应已完成,不标记为失败/取消 # 如果响应已完成,不标记为失败/取消
if not ctx.has_completion: if not ctx.has_completion:
if is_client_disconnected: if is_client_disconnected:
ctx.status_code = 499 ctx.status_code = 499
ctx.error_message = "client_disconnected" ctx.error_message = "client_disconnected"
cancel_origin = "client_disconnected"
logger.warning( logger.warning(
f"ID:{ctx.request_id} | Stream cancelled by client: " f"ID:{ctx.request_id} | Stream cancelled by client: "
f"chunks={chunk_count}, " f"chunks={chunk_count}, "
@@ -138,10 +194,23 @@ class CliMonitorMixin:
f"time_since_last_chunk={time_since_last_chunk:.2f}s, " f"time_since_last_chunk={time_since_last_chunk:.2f}s, "
f"output_tokens={ctx.output_tokens}" f"output_tokens={ctx.output_tokens}"
) )
elif disconnect_check_uncertain:
# 断连检查本身不稳定(超时/取消/异常)时,避免直接定性为 server_cancelled。
ctx.status_code = 503
ctx.error_message = "cancelled_unknown"
cancel_origin = "cancelled_unknown"
logger.warning(
f"ID:{ctx.request_id} | Stream cancelled with unknown origin: "
f"chunks={chunk_count}, "
f"has_completion={ctx.has_completion}, "
f"time_since_last_chunk={time_since_last_chunk:.2f}s, "
f"output_tokens={ctx.output_tokens}"
)
else: else:
# 服务端中断(例如重载/关停/内部取消) -- 不应伪装成客户端取消 # 服务端中断(例如重载/关停/内部取消) -- 不应伪装成客户端取消
ctx.status_code = 503 ctx.status_code = 503
ctx.error_message = "server_cancelled" ctx.error_message = "server_cancelled"
cancel_origin = "server_cancelled"
logger.error( logger.error(
f"ID:{ctx.request_id} | Stream interrupted by server: " f"ID:{ctx.request_id} | Stream interrupted by server: "
f"chunks={chunk_count}, " f"chunks={chunk_count}, "
@@ -149,6 +218,13 @@ class CliMonitorMixin:
f"time_since_last_chunk={time_since_last_chunk:.2f}s, " f"time_since_last_chunk={time_since_last_chunk:.2f}s, "
f"output_tokens={ctx.output_tokens}" f"output_tokens={ctx.output_tokens}"
) )
ctx.upstream_response = (
f"cancel_origin={cancel_origin}, "
f"chunks={chunk_count}, "
f"has_completion={ctx.has_completion}, "
f"time_since_last_chunk={time_since_last_chunk:.2f}s, "
f"output_tokens={ctx.output_tokens}"
)
raise raise
except httpx.TimeoutException as e: except httpx.TimeoutException as e:
ctx.status_code = 504 ctx.status_code = 504

View File

@@ -658,11 +658,11 @@ class CliStreamMixin:
url=url, url=url,
headers=provider_headers, headers=provider_headers,
payload=provider_payload, payload=provider_payload,
timeout=( # 流式请求不应使用 provider.request_timeout 作为“整条流总时长”超时,
provider.request_timeout or config.http_request_timeout # 否则会在长响应中途被硬切断(常见于 request_timeout=15s 的配置)。
if delegate_cfg # 首字节超时由外层 wait_for(stream_first_byte_timeout) 控制;
else None # 后续分块读取由 http client 默认 read timeout长超时控制。
), timeout=None,
) )
_connect_start = time.monotonic() _connect_start = time.monotonic()
response_ctx = http_client.stream(**_skw) response_ctx = http_client.stream(**_skw)

View File

@@ -0,0 +1,87 @@
from __future__ import annotations
import asyncio
from collections.abc import AsyncGenerator
import pytest
from src.api.handlers.base.cli_monitor_mixin import CliMonitorMixin
from src.api.handlers.base.stream_context import StreamContext
class _DummyMonitor(CliMonitorMixin):
pass
class _RequestStub:
def __init__(self, responses: list[bool | Exception]):
self._responses = responses
async def is_disconnected(self) -> bool:
if self._responses:
value = self._responses.pop(0)
else:
value = False
if isinstance(value, Exception):
raise value
return value
async def _cancel_immediately() -> AsyncGenerator[bytes, None]:
if False:
yield b""
raise asyncio.CancelledError()
@pytest.mark.asyncio
async def test_create_monitored_stream_marks_client_disconnected_when_confirmed() -> None:
monitor = _DummyMonitor()
monitor.CANCEL_DISCONNECT_RETRY_DELAYS_SECONDS = ()
ctx = StreamContext(model="test-model", api_format="openai:cli", request_id="req-client")
request = _RequestStub([True])
monitored = monitor._create_monitored_stream(ctx, _cancel_immediately(), request)
with pytest.raises(asyncio.CancelledError):
async for _ in monitored:
pass
assert ctx.status_code == 499
assert ctx.error_message == "client_disconnected"
assert "cancel_origin=client_disconnected" in (ctx.upstream_response or "")
@pytest.mark.asyncio
async def test_create_monitored_stream_marks_server_cancelled_when_confirmed_connected() -> None:
monitor = _DummyMonitor()
monitor.CANCEL_DISCONNECT_RETRY_DELAYS_SECONDS = ()
ctx = StreamContext(model="test-model", api_format="openai:cli", request_id="req-server")
request = _RequestStub([False])
monitored = monitor._create_monitored_stream(ctx, _cancel_immediately(), request)
with pytest.raises(asyncio.CancelledError):
async for _ in monitored:
pass
assert ctx.status_code == 503
assert ctx.error_message == "server_cancelled"
assert "cancel_origin=server_cancelled" in (ctx.upstream_response or "")
@pytest.mark.asyncio
async def test_create_monitored_stream_marks_cancelled_unknown_when_disconnect_check_uncertain() -> None:
monitor = _DummyMonitor()
monitor.CANCEL_DISCONNECT_RETRY_DELAYS_SECONDS = ()
ctx = StreamContext(model="test-model", api_format="openai:cli", request_id="req-unknown")
request = _RequestStub([asyncio.TimeoutError()])
monitored = monitor._create_monitored_stream(ctx, _cancel_immediately(), request)
with pytest.raises(asyncio.CancelledError):
async for _ in monitored:
pass
assert ctx.status_code == 503
assert ctx.error_message == "cancelled_unknown"
assert "cancel_origin=cancelled_unknown" in (ctx.upstream_response or "")