Skip to content

Commit 230d83d

Browse files
committed
fix(logs,tasks): 异常日志补类名,签到失败改指数退避
- 新增 error_text:裸 TimeoutError/ConnectError 的 str 为空,原日志只剩 「quota probe failed for cred_x: 」,额度探测 89/91 条、动态模型拉取 54/58 条无法定位;统一输出「类名: 消息」。 - 签到连续失败按 10m→20m→40m→1h 退避,成功清零、跨天清理;管理台手动 运行绕过退避。修两个号每 10 分钟空锤一整天、145 条 WARNING 的噪声。
1 parent cd62890 commit 230d83d

11 files changed

Lines changed: 294 additions & 13 deletions

File tree

‎src/error_text.py‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,25 @@
1+
"""异常 → 一行日志/展示文本。
2+
3+
`str(error)` 对部分异常为空(`TimeoutError`、某些 `httpx.ConnectError`),
4+
直接 `"%s" % error` 会打出「quota probe failed for cred_x: 」这种无因日志
5+
(2026-11 实测 89/91 条额度探测失败、54/58 条动态模型拉取失败都是空原因),
6+
排障时只能看到「失败了」却不知道是超时、DNS 还是协议错误。
7+
8+
统一带上异常类名,保证至少能区分大类;有消息时保留消息(压缩空白、限长)。
9+
"""
10+
11+
from __future__ import annotations
12+
13+
import re
14+
15+
_WHITESPACE = re.compile(r"\s+")
16+
17+
18+
def error_text(error: BaseException, *, limit: int = 200) -> str:
19+
"""异常 → `类名: 消息`;消息为空时只有类名(如 `TimeoutError`)。"""
20+
message = _WHITESPACE.sub(" ", str(error)).strip()
21+
if not message:
22+
return type(error).__name__
23+
if len(message) > limit:
24+
message = message[:limit] + "…"
25+
return f"{type(error).__name__}: {message}"

‎src/provider/codebuddy/client.py‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,7 @@
2626

2727
from ...engine.affinity import resolve_explicit
2828
from ...engine.sse import iter_frames
29+
from ...error_text import error_text
2930
from ...provider import base
3031
from ...provider.base import ErrKind, Event, GrowthResult, Model, Quota
3132
from ...tasks.pacer import paced
@@ -862,7 +863,8 @@ async def list_models(self, credential_data: dict) -> list[Model]:
862863
except Exception as error: # noqa: BLE001 - 兜底不是静默:错误会带上抛路径
863864
import logging
864865

865-
logging.getLogger(__name__).warning("动态模型拉取失败,回退静态表: %s", error)
866+
logging.getLogger(__name__).warning("动态模型拉取失败,回退静态表: %s",
867+
error_text(error))
866868
return [Model(id=mid) for mid in DEFAULT_MODELS]
867869

868870
async def stream_chat(self, credential_data: dict, payload: dict,

‎src/provider/trae/client.py‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616
import httpx
1717

1818
from ...engine.sse import iter_frames
19+
from ...error_text import error_text
1920
from ...provider import base
2021
from ...provider.base import (
2122
AuthFlow,
@@ -696,7 +697,7 @@ async def list_models(self, credential_data: dict) -> list[Model]:
696697

697698
self._dynamic_models_blocked_until = time.monotonic() + 300
698699
logging.getLogger(__name__).warning(
699-
"TRAE 动态模型拉取失败,回退静态表 5 分钟: %s", error)
700+
"TRAE 动态模型拉取失败,回退静态表 5 分钟: %s", error_text(error))
700701
# 静态表:重名时 id 用实测大小写,元数据优先取动态结果,
701702
# 其次取上次成功的动态拉取(负缓存期倍率不丢)
702703
merged: list[Model] = []

‎src/tasks/checkin.py‎

Lines changed: 48 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212
from ..config import live
1313
from ..db.crypto import CredentialDecryptError
1414
from ..db.repo import CredentialRepository
15+
from ..error_text import error_text
1516
from ..request_context import credential_scope
1617
from . import TaskReport
1718
from .pacer import Pacer
@@ -24,6 +25,13 @@
2425
# 与 `engine/limits.day_start`、`tasks/activity` 同一口径。
2526
_CN_TZ = ZoneInfo("Asia/Shanghai")
2627

28+
#: 失败重试退避:首轮失败后 10 分钟再试,连续失败翻倍,封顶 1 小时。
29+
#: 上游对「今日积分尚未发放」会一直回同一句(实测 2026-11-05 两个号从 00:29
30+
#: 到 17:54 每 10 分钟锤一次 → 145 条 WARNING + 几千次无效上游调用)。
31+
#: 退避后一天最多 ~7 次/账号,仍能在当天补签;`trigger="manual"` 不受限制。
32+
_FAIL_BACKOFF_BASE = 10 * 60
33+
_FAIL_BACKOFF_MAX = 60 * 60
34+
2735

2836
def _cn_now(now: int | None = None) -> time.struct_time:
2937
"""当前时刻的北京时间 struct_time(测试可注入 epoch 秒)。
@@ -101,6 +109,9 @@ def __init__(self, credentials: CredentialRepository, providers: dict,
101109
# 注意与下面的「时点放行」是两套键:这里是每个凭证/G 作用域的封账,
102110
# 那边是「今天这个时点已经触发过一轮」,语义不能合并。
103111
self._done_scopes: dict[str, int] = {}
112+
# done_key → (连续失败次数, 下次允许重试的 epoch 秒)。失败退避,成功清零;
113+
# 与 `_done_scopes` 同键同生命周期,跨天 prune 时一起清。
114+
self._failures: dict[str, tuple[int, int]] = {}
104115
# 时点放行:键固定为「本地日期 + 时点分钟数」,抖动只改窗口、不改归属,
105116
# 所以执行时刻落在窗口里哪个分钟都不会让同一时点跑两次。
106117
self._slot_offsets: dict[str, int] = {} # 当日该时点抽到的抖动偏移(分钟)
@@ -178,26 +189,52 @@ def _prune(self, now: time.struct_time) -> None:
178189
"""丢掉非当天的封账记录:done_key 以日期开头,跨天后不可能再命中,
179190
长驻进程否则每天每账号各攒一条(无上限)。"""
180191
day = self._day_key(now)
181-
stale = [key for key in self._done_scopes if not key.startswith(f"{day}:")]
192+
prefix = f"{day}:"
193+
stale = [key for key in self._done_scopes if not key.startswith(prefix)]
182194
for key in stale:
183195
del self._done_scopes[key]
196+
for key in [key for key in self._failures if not key.startswith(prefix)]:
197+
del self._failures[key]
184198

185199
def _sealed(self, done_key: str, now: time.struct_time) -> bool:
186200
"""该作用域是否已封账且封账未到期。"""
187201
until = self._done_scopes.get(done_key)
188202
return until is not None and until > _cn_epoch(now)
189203

204+
def _backed_off(self, done_key: str, now: time.struct_time,
205+
*, manual: bool) -> bool:
206+
"""失败退避未到期 → 本轮跳过;管理台「立即运行」不受退避限制。"""
207+
if manual:
208+
return False
209+
state = self._failures.get(done_key)
210+
return state is not None and state[1] > _cn_epoch(now)
211+
212+
def _note_failure(self, done_key: str, now: time.struct_time) -> None:
213+
"""记一次失败并按连续失败次数翻倍退避(10m → 20m → 40m → 封顶 1h)。"""
214+
streak = self._failures.get(done_key, (0, 0))[0] + 1
215+
delay = min(_FAIL_BACKOFF_BASE * 2 ** min(streak - 1, 6), _FAIL_BACKOFF_MAX)
216+
self._failures[done_key] = (streak, _cn_epoch(now) + delay)
217+
218+
def _clear_failure(self, done_key: str) -> None:
219+
"""成功即清零:下次再失败从 10 分钟重新起算,不继承旧的退避档位。"""
220+
self._failures.pop(done_key, None)
221+
190222
async def run_once(self, *, now: time.struct_time | int | None = None,
191223
trigger: str = "auto") -> TaskReport:
192224
"""签到一轮:已成功(当日封账)的作用域直接跳过;失败的留到下轮重试。
193225
194-
`trigger` 只进审计日志(auto=定时 / manual=管理台「立即运行」),不参与
195-
任何判定。
226+
失败按连续次数做指数退避(10m → 20m → 40m → 封顶 1h),避免上游
227+
一直回「积分尚未发放」时每 10 分钟空锤一次;`trigger="manual"`
228+
(管理台立即运行)绕过退避。失败不封账,成功才封账。
229+
230+
`trigger` 只进审计日志(auto=定时 / manual=管理台「立即运行」),
231+
除绕过失败退避外不参与任何判定。
196232
"""
197233
current = now if isinstance(now, time.struct_time) else _cn_now(now)
198234
day = self._day_key(current)
199235
report = TaskReport()
200236
seen: set[str] = set()
237+
manual = trigger == "manual"
201238
self._prune(current)
202239
for candidate in self._credentials.candidates():
203240
# `enabled=0`(用户软暂停)同样跳过,口径与调度器 is_selectable 一致。
@@ -232,6 +269,9 @@ async def run_once(self, *, now: time.struct_time | int | None = None,
232269
report.skipped += 1 # 同一轮同上游账号只签一次
233270
continue
234271
seen.add(scope)
272+
if self._backed_off(done_key, current, manual=manual):
273+
report.skipped += 1 # 退避未到期,不调上游
274+
continue
235275
report.attempted += 1
236276
# 签到一轮含 status+claim+回查三次上游调用,与 quota_probe/growth
237277
# 共用同一 Pacer,避免绕开全局频率风控对策
@@ -241,11 +281,14 @@ async def run_once(self, *, now: time.struct_time | int | None = None,
241281
with credential_scope(candidate.credential_id):
242282
result = await provider.checkin(data)
243283
except Exception as error: # noqa: BLE001
244-
logger.warning("checkin failed for %s: %s", candidate.credential_id, error)
284+
logger.warning("checkin failed for %s: %s", candidate.credential_id,
285+
error_text(error))
286+
self._note_failure(done_key, current)
245287
report.failed += 1
246288
continue
247289
if result.ok:
248290
report.succeeded += 1
291+
self._clear_failure(done_key)
249292
# 成功即封账该作用域:封账期内不再重试,失败凭证不受影响可继续
250293
# 重试。渠道给了 `seal_until` 就按它封(签到周期 ≠ 自然日,
251294
# 见 `CheckinResult.seal_until`),否则封到本地当日结束。
@@ -254,6 +297,7 @@ async def run_once(self, *, now: time.struct_time | int | None = None,
254297
self._on_success(candidate.credential_id)
255298
else:
256299
report.failed += 1
300+
self._note_failure(done_key, current)
257301
logger.warning("checkin failed for %s: %s",
258302
candidate.credential_id, result.message or "未知原因")
259303
# 审计日志:成功/失败/已签都记一行(上游异常没有 result 时不记)。

‎src/tasks/quota_probe.py‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@
66

77
from ..db.crypto import CredentialDecryptError
88
from ..db.repo import CredentialRepository
9+
from ..error_text import error_text
910
from ..provider.base import Quota
1011
from ..request_context import credential_scope
1112
from . import TaskReport
@@ -57,7 +58,8 @@ async def run_once(self, *, apply_pacing: bool = True) -> TaskReport:
5758
with credential_scope(candidate.credential_id):
5859
quota = await provider.probe_quota(data)
5960
except Exception as error: # noqa: BLE001 - 探测失败不能中断整批
60-
logger.warning("quota probe failed for %s: %s", candidate.credential_id, error)
61+
logger.warning("quota probe failed for %s: %s", candidate.credential_id,
62+
error_text(error))
6163
# 探测失败 → health 置 NULL(unknown),绝不当作 0 分
6264
self._credentials.mark_probe_failed(candidate.credential_id)
6365
report.failed += 1

‎tests/provider/codebuddy/test_client_models.py‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -146,3 +146,16 @@ def handler(_request: httpx.Request) -> httpx.Response:
146146

147147
with pytest.raises(UpstreamProtocolViolation):
148148
await _client(handler).fetch_models(CodeBuddyCredential(bearer_token="t"))
149+
150+
151+
async def test_provider_list_models_log_includes_type_when_message_empty(caplog):
152+
"""裸 `TimeoutError` 消息为空 → 回退日志仍要带类名,不能只剩「: 」。"""
153+
class _Client:
154+
async def fetch_models(self, _credential):
155+
raise TimeoutError()
156+
157+
provider = CodeBuddyProvider(client=_Client())
158+
with caplog.at_level("WARNING", logger="src.provider.codebuddy.client"):
159+
models = await provider.list_models({"bearer_token": "t"})
160+
assert [m.id for m in models] == list(DEFAULT_MODELS)
161+
assert any("TimeoutError" in record.getMessage() for record in caplog.records)

‎tests/provider/trae/test_client.py‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -550,3 +550,16 @@ def handler(_request: httpx.Request) -> httpx.Response:
550550
# extra_info 之后的事件都带上真实模型名
551551
assert usage.model == "glm-5.2-real"
552552
assert finish.model == "glm-5.2-real"
553+
554+
555+
async def test_provider_model_failure_log_includes_type_when_message_empty(caplog):
556+
"""裸 `TimeoutError` 消息为空 → 回退日志仍要带类名,不能只剩「: 」。"""
557+
class _Client:
558+
async def fetch_models(self, _credential):
559+
raise TimeoutError()
560+
561+
provider = TraeProvider(client=_Client())
562+
with caplog.at_level("WARNING", logger="src.provider.trae.client"):
563+
models = await provider.list_models({"accessToken": "a", "uid": "u"})
564+
assert [m.id for m in models] == list(STATIC_MODELS)
565+
assert any("TimeoutError" in record.getMessage() for record in caplog.records)

0 commit comments

Comments
 (0)