From f90f7b036c63a5ac9aeca077b13a5740aea63697 Mon Sep 17 00:00:00 2001 From: iomgaa Date: Mon, 24 Aug 2026 11:45:32 -0400 Subject: [PATCH] test: give the log level and ownership rules real enforcement MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 两条"确证的假绿"(独立验证发现): ① 设计 §3.2 的"配置级致命发 error 而非 warning"没有执法点: `captured_warnings` fixture 挂在 level="WARNING",ERROR 与 WARNING 同池,且 tracker 自己那条 WARNING 文案就含"重启"——把 recorder 的 `logger.error` 整块删掉,原用例照样绿。新增 `captured_logs` fixture 连级别一起捕获,三处补上级别断言。 顺带消掉实现与设计的偏离: 原实现同时发 1 条 ERROR(recorder)+ 1 条 语义重复的 WARNING(tracker)。级别决策收敛到 tracker 一处(fatal → error,其余 → warning),recorder 侧不再另发,SQLite 侧同时受益。 ② 所有权判定的 `is None` / `is not None` 纪律(设计 §3.4)零覆盖: 所有假件都是 truthy,把工厂改回 `limiter or _build_limiter(...)` 全套件照样绿。补 `_FalsyClosable`(`__bool__` 返 False)与三个工厂 各一条用例: 注入 falsy 后端时工厂不得自建、`_owns_*` 为 False、 `aclose` 不得关它。 --- src/polygateway/telemetry/postgres.py | 9 +-- src/polygateway/telemetry/status.py | 11 ++- tests/unit/test_client.py | 111 ++++++++++++++++++++++++++ tests/unit/test_telemetry.py | 50 ++++++++++-- 4 files changed, 168 insertions(+), 13 deletions(-) diff --git a/src/polygateway/telemetry/postgres.py b/src/polygateway/telemetry/postgres.py index 8a32589..4cc4127 100644 --- a/src/polygateway/telemetry/postgres.py +++ b/src/polygateway/telemetry/postgres.py @@ -376,12 +376,9 @@ class PostgresRecorder: """ verdict = _classify_failure(exc) if verdict == _FATAL: - # error 而非 warning: 这是人配错了,且本进程内不会自愈,运维要看见 - logger.error( - "Postgres 遥测{}失败: 配置有误,本进程内不会自愈(请修正 DSN 后重启): {}", - stage, - exc, - ) + # 这里**不再**另发一条 error: 级别由 tracker 按 `fatal` 决定(致命档发 + # error——人配错了,本进程内不会自愈)。此处复制一条只会让同一个事实出 + # 两条语义重复的日志,并给"级别"这个决策造出第二个源头 self._status.enter_degraded( f"{stage}失败(配置有误): {exc}", fatal=True, cooldown_s=None ) diff --git a/src/polygateway/telemetry/status.py b/src/polygateway/telemetry/status.py index 17cbe07..2665e05 100644 --- a/src/polygateway/telemetry/status.py +++ b/src/polygateway/telemetry/status.py @@ -66,7 +66,8 @@ class TelemetryStatusTracker: Args: reason: 降级原因(已含具体异常文本);同值视为同一次降级的续期。 - fatal: True = 本进程内不可恢复,此后 `should_retry()` 恒 False。 + fatal: True = 本进程内不可恢复,此后 `should_retry()` 恒 False; + **同时决定日志级别**(见下方发日志处)。 cooldown_s: 距下次允许重新准备的秒数;None 表示不自动重试。 """ if self._fatal: @@ -83,7 +84,13 @@ class TelemetryStatusTracker: self._fatal = fatal self._retry_at = None if fatal or cooldown_s is None else now + cooldown_s if announce: - logger.warning( + # 级别由 `fatal` 决定,且**只在这一处**决定(设计 §3.2): 致命档是"人把 + # 配置写错了、本进程内不会自愈",运维必须看见 → error;其余都是外部 + # 状态、会自愈 → warning。recorder 侧一度各自再发一条 error,同一个 + # 事实因此出两条语义重复的日志,"级别"这个决策也就有了两个源头——两个 + # 源头必然漂移,正是本 issue 反复踩的那类错 + emit = logger.error if fatal else logger.warning + emit( "{} 遥测降级(后续记录将被丢弃): {};恢复条件: {}", self._backend, reason, diff --git a/tests/unit/test_client.py b/tests/unit/test_client.py index 98b5d14..aa55ae2 100644 --- a/tests/unit/test_client.py +++ b/tests/unit/test_client.py @@ -585,10 +585,27 @@ class _SyncClosable: self.closed += 1 +class _FalsyClosable(_Closable): + """`bool()` 为假的组件(空容器形态的后端就长这样)。 + + 所有权判定必须写 `is None` / `is not None`,不得写 `or`(设计 §3.4,ARCH §4.5 + 细则 2): 写 `or` 时注入这样一个后端会**悄悄走自建分支**,而所有权标志按 + `is None` 判成 False——于是既没用上注入的那个,自建的那个又没人关,正是本 + issue 要修的泄漏原地复活。判定与标志一漂移,两个 bug 一起回来。 + """ + + def __bool__(self): + return False + + def _parts(*names): return {name: _Closable() for name in names} +def _falsy_parts(*names): + return {name: _FalsyClosable() for name in names} + + def _patch_builders(monkeypatch, built, *, transport_path): """把工厂的自建点换成可计数假件;transport 无注入入口,故恒自建。""" monkeypatch.setattr(transport_path, lambda **kwargs: built["transport"]) @@ -654,6 +671,38 @@ class TestGatewayClientOwnership: assert all(part.closed == 0 for part in injected.values()) assert built["transport"].closed == 1 # 工厂恒自建 transport,归 client + async def test_falsy_injected_components_are_still_injected(self, monkeypatch): + """`is not None` 是所有权判定成立的**必要条件**,不是风格偏好(设计 §3.4)。 + + 改回 `or` 时: 工厂拿自建件顶掉注入件(下游以为在共享,其实各跑各的), + 且自建件的 `_owns_*` 仍是 False —— redis 客户端就地泄漏。 + """ + built = _parts("transport", "telemetry", "cache", "limiter", "breaker") + _patch_builders(monkeypatch, built, transport_path=self._GATEWAY_TRANSPORT) + injected = _falsy_parts("telemetry", "cache", "limiter", "breaker") + client = GatewayClient.from_settings( + GatewaySettings.from_env("LLM", env=_CACHE_ENV), + limiter=injected["limiter"], + breaker=injected["breaker"], + cache=injected["cache"], + telemetry=injected["telemetry"], + ) + assert client._limiter_backend is injected["limiter"] + assert client._breaker_backend is injected["breaker"] + assert client._cache is injected["cache"] + assert client._telemetry is injected["telemetry"] + owns = (client._owns_limiter, client._owns_breaker, client._owns_cache) + assert owns == (False, False, False) and client._owns_telemetry is False + await client.aclose() + assert all(part.closed == 0 for part in injected.values()) + # 自建件根本不该被造出来更不该被关;只有恒自建的 transport 归 client + assert [built[name].closed for name in ("telemetry", "cache", "limiter", "breaker")] == [ + 0, + 0, + 0, + 0, + ] + async def test_aclose_is_idempotent(self, monkeypatch): built = _parts("transport", "telemetry", "cache", "limiter", "breaker") _patch_builders(monkeypatch, built, transport_path=self._GATEWAY_TRANSPORT) @@ -746,6 +795,39 @@ class TestEmbeddingClientOwnership: assert all(part.closed == 0 for part in injected.values()) assert built["transport"].closed == 1 + async def test_falsy_injected_components_are_still_injected(self, monkeypatch): + """三处工厂各写一遍 `is not None`,就是三处各有一次漂移回 `or` 的机会。""" + from polygateway.config import EmbeddingSettings + from polygateway.embedding import EmbeddingClient + + built = _parts("transport", "telemetry", "limiter", "breaker") + _patch_builders( + monkeypatch, + built, + transport_path="polygateway.transports.openai_compat.OpenAICompatTransport", + ) + injected = _falsy_parts("telemetry", "limiter", "breaker") + settings = EmbeddingSettings( + gateway=GatewaySettings.from_env("LLM", env=_ENV), batch_size=2 + ) + client = EmbeddingClient.from_settings( + settings, + limiter=injected["limiter"], + breaker=injected["breaker"], + telemetry=injected["telemetry"], + ) + assert client._limiter_backend is injected["limiter"] + assert client._breaker_backend is injected["breaker"] + assert client._telemetry is injected["telemetry"] + assert (client._owns_limiter, client._owns_breaker, client._owns_telemetry) == ( + False, + False, + False, + ) + await client.aclose() + assert all(part.closed == 0 for part in injected.values()) + assert [built[name].closed for name in ("telemetry", "limiter", "breaker")] == [0, 0, 0] + def _ocr_client(**overrides): from polygateway.ocr import OcrClient @@ -811,6 +893,35 @@ class TestOcrClientOwnership: assert all(part.closed == 0 for part in injected.values()) assert built["transport"].closed == 1 + async def test_falsy_injected_components_are_still_injected(self, monkeypatch): + from polygateway.config import OcrSettings + from polygateway.ocr import OcrClient + + built = _parts("transport", "telemetry", "limiter", "breaker") + _patch_builders( + monkeypatch, + built, + transport_path="polygateway.transports.monkey_ocr.MonkeyOcrTransport", + ) + injected = _falsy_parts("telemetry", "limiter", "breaker") + client = OcrClient.from_settings( + OcrSettings.from_env("OCR", env=dict(_OCR_ENV)), + limiter=injected["limiter"], + breaker=injected["breaker"], + telemetry=injected["telemetry"], + ) + assert client._limiter_backend is injected["limiter"] + assert client._breaker_backend is injected["breaker"] + assert client._telemetry is injected["telemetry"] + assert (client._owns_limiter, client._owns_breaker, client._owns_telemetry) == ( + False, + False, + False, + ) + await client.aclose() + assert all(part.closed == 0 for part in injected.values()) + assert [built[name].closed for name in ("telemetry", "limiter", "breaker")] == [0, 0, 0] + class TestRedisCacheOwnership: """组件内部自建的连接归组件自己;照抄 RedisLimiter._owns_client 的正确先例。""" diff --git a/tests/unit/test_telemetry.py b/tests/unit/test_telemetry.py index cb0626b..dd473a7 100644 --- a/tests/unit/test_telemetry.py +++ b/tests/unit/test_telemetry.py @@ -147,6 +147,25 @@ def captured_warnings(): logger.remove(sink_id) +@pytest.fixture +def captured_logs(): + """捕获 WARNING 及以上的日志**连同级别**,产出 `(级别名, 文案)` 列表。 + + 与 `captured_warnings` 分开存在是有理由的: 后者只留文案,而 ERROR 与 WARNING + 在 `level="WARNING"` 的 sink 里同池——于是"配置级致命发 error 而非 warning" + 这条设计决策(§3.2)长期**没有执法点**,把发 error 的那几行整块删掉,原有用例 + 照样全绿。级别是决策的一部分,就必须能被断言。 + """ + from loguru import logger + + records: list[tuple[str, str]] = [] + sink_id = logger.add( + lambda m: records.append((m.record["level"].name, m.record["message"])), level="WARNING" + ) + yield records + logger.remove(sink_id) + + # 搬迁前(1.2.1)两个 recorder 各自持有的 INSERT 常量原文,逐字冻结在此。 # 这两条字符串是"纯搬迁不改行为"的机械证据: 构造逻辑换了地方,产物必须一字不差。 _FROZEN_SQLITE_INSERT = ( @@ -1888,6 +1907,17 @@ class TestTelemetryStatusTracker: assert tracker.should_retry() is False assert "重启" in captured_warnings[0] # 恢复条件必须写在日志里 + def test_log_level_is_decided_by_fatal_and_only_here(self, captured_logs): + """级别决策**收敛在 tracker 一处**: fatal → ERROR,其余 → WARNING(设计 §3.2)。 + + 这是那条决策在全库唯一的执法点。它同时钉两个方向: 把 fatal 那档改回 + warning 会红,把两档都提成 error 也会红——"人配错了"与"外部挂了"必须 + 在日志级别上分得开,运维的告警规则就架在这个区分上。 + """ + self._tracker(_FakeClock()).enter_degraded("DSN 不可解析", fatal=True, cooldown_s=None) + self._tracker(_FakeClock()).enter_degraded("连接被拒", fatal=False, cooldown_s=60.0) + assert [level for level, _ in captured_logs] == ["ERROR", "WARNING"] + def test_repeating_the_same_reason_does_not_spam(self, captured_warnings): """冷却到期重试再失败会反复进入降级: 同一原因只讲一次,只刷新窗口。""" clock = _FakeClock() @@ -1908,11 +1938,13 @@ class TestSQLiteStatusVisibility: blocker.write_text("父目录是个文件,mkdir 必然失败") return SQLiteRecorder(blocker / "telemetry.db", auto_migrate=True) - def test_init_failure_is_degraded_and_fatal(self, tmp_path, captured_warnings): + def test_init_failure_is_degraded_and_fatal(self, tmp_path, captured_logs): recorder = self._broken(tmp_path) status = recorder.telemetry_status assert status.degraded is True and status.fatal is True - assert captured_warnings # 静默降级 ≠ 静默 + # 静默降级 ≠ 静默;且致命档两侧同级别——tracker 是级别的唯一决策点, + # SQLite 侧不该因为没人复制那条 error 就降一级 + assert [(level, "重启" in m) for level, m in captured_logs] == [("ERROR", True)] async def test_dropped_rows_are_counted_and_visible(self, tmp_path, captured_warnings): recorder = self._broken(tmp_path) @@ -2291,8 +2323,13 @@ class TestPostgresFailureClassification: assert recorder.telemetry_status.degraded is False # 自愈,无需重启进程 assert recorder.telemetry_status.dropped_rows == 2 # 降级期间那两行确实丢了 - async def test_unparseable_dsn_is_fatal_and_costs_nothing_afterwards(self, captured_warnings): - """DSN 是构造期定死的字符串: 唯一"进程内不可能变好"的东西,故唯一的致命档。""" + async def test_unparseable_dsn_is_fatal_and_costs_nothing_afterwards(self, captured_logs): + """DSN 是构造期定死的字符串: 唯一"进程内不可能变好"的东西,故唯一的致命档。 + + 级别与条数一起断言: 同一个事实只该出一条 **ERROR**。recorder 侧曾在 tracker + 之外另发一条,于是同一次配置错误刷出 error + warning 两条语义重复的日志, + 而"级别"这个决策也就有了两个源头(设计 §3.2)。 + """ import asyncpg clock = _FakeClock() @@ -2306,7 +2343,10 @@ class TestPostgresFailureClassification: status = recorder.telemetry_status assert status.degraded is True and status.fatal is True assert status.retry_after_s is None # 本进程内不会自愈 - assert any("重启" in m for m in captured_warnings) # 恢复条件必须写在日志里 + # 按"恢复条件"这个标记捞降级播报本身(丢行复述是另一个事实,不在此列): + # 同一次配置错误只该播报**一条**,且级别是 error + announced = [(level, m) for level, m in captured_logs if "重启" in m] + assert [level for level, _ in announced] == ["ERROR"] clock.advance(1_000_000.0) attempts = len(pool.acquire_timeouts)