feat: make telemetry degradation a first-class state
Telemetry degradation used to be a single warning and a private boolean. In a long-running process that is indistinguishable from telemetry working: issue #15 was only found by hand-reconciling milestone log lines against llm_calls rows, after 19 calls had silently gone unrecorded. The SQLite side was worse — once init failed, every write returned without even a log line. Degradation now has one shared owner. TelemetryStatusTracker holds the state machine (enter/recover/drop/should-retry), announces entry and recovery once each, and repeats the drop count under a row-and-time double threshold so a degraded backend neither floods the log nor goes quiet. Both recorders hold one; both count the rows they drop. For programmatic consumers, TelemetryStatus is a frozen snapshot exposed as telemetry_status on all three clients, resolved through a single isinstance check. It is a separate optional port rather than a member of TelemetryRecorder: that protocol is @runtime_checkable, so adding an attribute would make every implementation that only defines record_llm_call stop satisfying it — downstream isinstance assertions would break on upgrade. The existing assertion in test_ports.py is what keeps that decision honest. Failure criteria are deliberately untouched here: Postgres still treats a pool failure as permanent, only now visibly. `_failed` and the tracker therefore both carry the verdict for the span of this one change; the cooldown rework collapses them into the tracker alone.
This commit is contained in:
@@ -28,10 +28,13 @@ from polygateway.telemetry.schema import (
|
||||
insert_sql,
|
||||
missing_columns_warning,
|
||||
)
|
||||
from polygateway.telemetry.status import TelemetryStatusTracker
|
||||
|
||||
if TYPE_CHECKING:
|
||||
import asyncpg
|
||||
|
||||
from polygateway.types import TelemetryStatus
|
||||
|
||||
# 探测表是否存在;不需要任何权限,且与 INSERT 走同一套 search_path 解析
|
||||
_TABLE_EXISTS = "SELECT to_regclass('llm_calls')"
|
||||
|
||||
@@ -72,8 +75,16 @@ class PostgresRecorder:
|
||||
self._insert = insert_sql("postgres", COLUMNS)
|
||||
self._schema_ready = False
|
||||
self._failed = False # 结构性降级标志: 置位后所有写入短路
|
||||
# 降级的可编程出口与节流日志;`_failed` 与它并存是 issue #15 的过渡态,
|
||||
# 判据改造(冷却自愈)落地时状态收归 tracker 一处
|
||||
self._status = TelemetryStatusTracker(backend="postgres")
|
||||
self._init_lock = asyncio.Lock()
|
||||
|
||||
@property
|
||||
def telemetry_status(self) -> TelemetryStatus:
|
||||
"""当前可写状态快照(ports.TelemetryStatusProvider)。"""
|
||||
return self._status.snapshot()
|
||||
|
||||
async def _ensure_ready(self) -> asyncpg.Pool | None:
|
||||
"""lazy 建池+备表;判死只认「确定写不进去」(issue #9),其余失败都留活路。"""
|
||||
if self._failed:
|
||||
@@ -104,7 +115,7 @@ class PostgresRecorder:
|
||||
# 池建不出来 = 确定写不进去;且每次调用重试都要内联吞掉 connect
|
||||
# 超时,而遥测是业务路径上的 await —— 此处必须永久降级
|
||||
self._failed = True
|
||||
logger.warning("Postgres 遥测建池失败,后续记录降级为 no-op: {}", exc)
|
||||
self._status.enter_degraded(f"建池失败: {exc}", fatal=True, cooldown_s=None)
|
||||
return None
|
||||
return self._pool
|
||||
|
||||
@@ -122,6 +133,9 @@ class PostgresRecorder:
|
||||
return None
|
||||
if columns is None:
|
||||
self._failed = True
|
||||
self._status.enter_degraded(
|
||||
"表 llm_calls 不存在且建不出来(记录无处可落)", fatal=True, cooldown_s=None
|
||||
)
|
||||
return None
|
||||
# 写入列、语句与就绪标志必须**一起**生效: `_ensure_ready` 只看 `_schema_ready`
|
||||
# 就绕开 `_init_lock` 直接返回池,先置就绪会开出"已就绪但语句还是旧的"的窗口
|
||||
@@ -232,6 +246,8 @@ class PostgresRecorder:
|
||||
"""
|
||||
pool = await self._ensure_ready()
|
||||
if pool is None:
|
||||
# 降级期间静默 return 就是 issue #15 的破口: 丢行必须计数且节流出声
|
||||
self._status.record_drop("遥测已降级")
|
||||
return
|
||||
row = tuple(fields[col] for col in self._columns)
|
||||
try:
|
||||
|
||||
@@ -19,6 +19,7 @@ import asyncio
|
||||
import sqlite3
|
||||
import threading
|
||||
from pathlib import Path
|
||||
from typing import TYPE_CHECKING
|
||||
|
||||
from loguru import logger
|
||||
|
||||
@@ -29,6 +30,10 @@ from polygateway.telemetry.schema import (
|
||||
insert_sql,
|
||||
missing_columns_warning,
|
||||
)
|
||||
from polygateway.telemetry.status import TelemetryStatusTracker
|
||||
|
||||
if TYPE_CHECKING:
|
||||
from polygateway.types import TelemetryStatus
|
||||
|
||||
|
||||
class SQLiteRecorder:
|
||||
@@ -45,6 +50,9 @@ class SQLiteRecorder:
|
||||
config 一处,不与本类签名漂移(设计 D-c)。
|
||||
"""
|
||||
self._auto_migrate = auto_migrate
|
||||
# SQLite 侧本次只做可见性: 它的失败模式(目录不可写、文件损坏)在装配期
|
||||
# 就暴露给下游,不是"跑到一半悄悄断",故降级恒为 fatal,不做冷却重连
|
||||
self._status = TelemetryStatusTracker(backend="sqlite")
|
||||
self._lock = threading.Lock()
|
||||
self._conn: sqlite3.Connection | None = None
|
||||
# 先按全量列定型: 连接失败/探测失败时保守沿用全量(今天的行为)
|
||||
@@ -60,9 +68,14 @@ class SQLiteRecorder:
|
||||
conn.commit()
|
||||
self._conn = conn
|
||||
except (OSError, sqlite3.Error) as exc:
|
||||
logger.warning("SQLite 遥测初始化失败,后续记录降级为 no-op: {}", exc)
|
||||
self._status.enter_degraded(f"初始化失败: {exc}", fatal=True, cooldown_s=None)
|
||||
self._prepare_columns()
|
||||
|
||||
@property
|
||||
def telemetry_status(self) -> TelemetryStatus:
|
||||
"""当前可写状态快照(ports.TelemetryStatusProvider)。"""
|
||||
return self._status.snapshot()
|
||||
|
||||
def _prepare_columns(self) -> None:
|
||||
"""探测现有列后定型写入: auto 档补齐缺列,manual 档改为裁剪写入(issue #13)。
|
||||
|
||||
@@ -136,6 +149,9 @@ class SQLiteRecorder:
|
||||
占位符同序——两者必须一起改,分开改就是把值写进错位的列。
|
||||
"""
|
||||
if self._conn is None:
|
||||
# 改前这里是**裸 return**: 初始化失败后每一行都无声消失,长跑进程里
|
||||
# 与"遥测正常"外观上完全一致(设计 §1.4 的直接钉子)
|
||||
self._status.record_drop("遥测已降级")
|
||||
return
|
||||
row = tuple(fields[col] for col in self._columns)
|
||||
try:
|
||||
|
||||
@@ -0,0 +1,178 @@
|
||||
"""遥测降级状态机(issue #15 C 组): 两个 recorder 共用的降级事实源。
|
||||
|
||||
存在的理由(设计 §1.4): 遥测降级过去只有**一条** warning,长跑进程里等同于
|
||||
静默——issue 是手工对账(日志里的完成里程碑条数 vs `llm_calls` 行数)才发现的,
|
||||
期间 19 次调用一行未落。"遥测必录"铁律的实质要求是: 库做不到必录时,必须
|
||||
**持续、可编程地**让下游知道。故降级升格为一等对象,两条出路各走一边:
|
||||
|
||||
- 人看: 进入/恢复各一条日志,降级期间按行数与时间**双阈值节流复述**(不刷屏,
|
||||
也不静默);
|
||||
- 程序看: `snapshot()` 给只读 `TelemetryStatus`,下游可据此对账或告警。
|
||||
|
||||
本模块**不含任何后端知识**(不 import asyncpg/sqlite3,也不判失败性质): 失败
|
||||
分类是各 recorder 的事,tracker 只接受"降级了/恢复了/丢了一行"三个事实。
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import time
|
||||
from typing import TYPE_CHECKING
|
||||
|
||||
from loguru import logger
|
||||
|
||||
from polygateway.types import TelemetryStatus
|
||||
|
||||
if TYPE_CHECKING:
|
||||
from collections.abc import Callable
|
||||
|
||||
_DROP_REPEAT_EVERY_ROWS = 100
|
||||
"""降级期间每丢这么多行复述一次;首行必报。"""
|
||||
|
||||
_DROP_REPEAT_EVERY_S = 300.0
|
||||
"""降级期间距上次复述超过这么久就再报一次——低频调用的进程不能因行数不够而静默。"""
|
||||
|
||||
|
||||
class TelemetryStatusTracker:
|
||||
"""单个 recorder 的降级状态;非线程安全,由持有它的 recorder 在自己的时序内使用。
|
||||
|
||||
时钟经构造参数注入(与 `GatewayClient(now=...)` 同款): 冷却窗口与节流窗口
|
||||
都必须能用假时钟测,否则这些行为只能靠真睡验证,而真睡的用例是间歇红的源头。
|
||||
"""
|
||||
|
||||
def __init__(self, *, backend: str, now: Callable[[], float] = time.monotonic) -> None:
|
||||
"""记下后端名(只用于日志前缀)与时钟;构造后即"未降级"。
|
||||
|
||||
Args:
|
||||
backend: 后端名(如 `postgres`/`sqlite`),仅进日志文案。
|
||||
now: 单调时钟;测试可注入假时钟推进冷却与节流窗口。
|
||||
"""
|
||||
self._backend = backend
|
||||
self._now = now
|
||||
self._degraded_since: float | None = None
|
||||
self._fatal = False
|
||||
self._reason: str | None = None
|
||||
self._retry_at: float | None = None
|
||||
self._dropped_rows = 0
|
||||
# 节流窗口: 本段降级里"自上次复述以来"丢了多少行、上次复述在什么时候
|
||||
self._dropped_since_report = 0
|
||||
self._last_report_at: float | None = None
|
||||
self._dropped_at_entry = 0
|
||||
|
||||
def enter_degraded(self, reason: str, *, fatal: bool, cooldown_s: float | None) -> None:
|
||||
"""进入(或续期)降级;同一原因只讲一次,只刷新冷却窗口。
|
||||
|
||||
不重复打日志是刚需而非优化: 冷却到期重试再失败会反复走到这里,每次都讲
|
||||
就把"降级中"刷成噪音。原因变了才算新事实,值得再讲一遍。
|
||||
|
||||
Args:
|
||||
reason: 降级原因(已含具体异常文本);同值视为同一次降级的续期。
|
||||
fatal: True = 本进程内不可恢复,此后 `should_retry()` 恒 False。
|
||||
cooldown_s: 距下次允许重新准备的秒数;None 表示不自动重试。
|
||||
"""
|
||||
if self._fatal:
|
||||
return # 永久档不可被后来的失败覆盖,也不再刷屏
|
||||
now = self._now()
|
||||
first_of_this_episode = self._degraded_since is None
|
||||
announce = first_of_this_episode or reason != self._reason
|
||||
if first_of_this_episode:
|
||||
self._degraded_since = now
|
||||
self._dropped_at_entry = self._dropped_rows
|
||||
self._dropped_since_report = 0
|
||||
self._last_report_at = None
|
||||
self._reason = reason
|
||||
self._fatal = fatal
|
||||
self._retry_at = None if fatal or cooldown_s is None else now + cooldown_s
|
||||
if announce:
|
||||
logger.warning(
|
||||
"{} 遥测降级(后续记录将被丢弃): {};恢复条件: {}",
|
||||
self._backend,
|
||||
reason,
|
||||
self._recovery_hint(cooldown_s, fatal=fatal),
|
||||
)
|
||||
|
||||
def recover(self) -> None:
|
||||
"""退出降级并报告本段期间丢了多少行;未降级时是 no-op。
|
||||
|
||||
`dropped_rows` **不清零**: 它是进程生命周期内的累计量,下游靠它对账。
|
||||
"""
|
||||
if self._degraded_since is None:
|
||||
return
|
||||
dropped = self._dropped_rows - self._dropped_at_entry
|
||||
logger.info(
|
||||
"{} 遥测已恢复(降级持续 {:.1f}s,期间丢弃 {} 行)",
|
||||
self._backend,
|
||||
self._now() - self._degraded_since,
|
||||
dropped,
|
||||
)
|
||||
self._degraded_since = None
|
||||
self._fatal = False
|
||||
self._reason = None
|
||||
self._retry_at = None
|
||||
self._dropped_since_report = 0
|
||||
self._last_report_at = None
|
||||
|
||||
def record_drop(self, reason: str) -> None:
|
||||
"""记一行被丢弃;按行数与时间双阈值节流复述。
|
||||
|
||||
双阈值缺一不可: 只按行数,低频调用的进程会长时间完全静默;只按时间,
|
||||
高频进程在窗口内丢几万行也只有一条日志,看不出量级。
|
||||
"""
|
||||
self._dropped_rows += 1
|
||||
self._dropped_since_report += 1
|
||||
if not self._should_report():
|
||||
return
|
||||
logger.warning(
|
||||
"{} 遥测丢弃记录(累计 {} 行): {}",
|
||||
self._backend,
|
||||
self._dropped_rows,
|
||||
reason,
|
||||
)
|
||||
self._dropped_since_report = 0
|
||||
self._last_report_at = self._now()
|
||||
|
||||
def should_retry(self) -> bool:
|
||||
"""现在是否允许(重新)准备后端: 纯查询,不触库也不改状态。
|
||||
|
||||
未降级 → True(本就该正常走准备路径);fatal → False;冷却未到 → False;
|
||||
非 fatal 但没给冷却 → False(调用方没安排自动重试,tracker 不替它决定)。
|
||||
"""
|
||||
if self._fatal:
|
||||
return False
|
||||
if self._degraded_since is None:
|
||||
return True
|
||||
if self._retry_at is None:
|
||||
return False
|
||||
return self._now() >= self._retry_at
|
||||
|
||||
def snapshot(self) -> TelemetryStatus:
|
||||
"""当前状态的只读快照(公共出口 `client.telemetry_status` 的取值点)。"""
|
||||
now = self._now()
|
||||
since = self._degraded_since
|
||||
retry_after_s: float | None = None
|
||||
if since is not None and self._retry_at is not None:
|
||||
retry_after_s = max(0.0, self._retry_at - now) # 到期后钳到 0,不给负数
|
||||
return TelemetryStatus(
|
||||
degraded=since is not None,
|
||||
fatal=self._fatal,
|
||||
reason=self._reason,
|
||||
degraded_for_s=None if since is None else now - since,
|
||||
dropped_rows=self._dropped_rows,
|
||||
retry_after_s=retry_after_s,
|
||||
)
|
||||
|
||||
def _should_report(self) -> bool:
|
||||
"""本次丢弃是否该出声: 本段降级的第一行、满行数阈值、或超时间阈值。"""
|
||||
if self._last_report_at is None:
|
||||
return True
|
||||
if self._dropped_since_report >= _DROP_REPEAT_EVERY_ROWS:
|
||||
return True
|
||||
return self._now() - self._last_report_at >= _DROP_REPEAT_EVERY_S
|
||||
|
||||
@staticmethod
|
||||
def _recovery_hint(cooldown_s: float | None, *, fatal: bool) -> str:
|
||||
"""把恢复条件写进日志: 运维看到降级后第一个问题就是"它自己会好吗"。"""
|
||||
if fatal:
|
||||
return "需修正配置后重启进程(本进程内不会自愈)"
|
||||
if cooldown_s is None:
|
||||
return "下次调用时重试"
|
||||
return f"约 {cooldown_s:.0f}s 后自动重试"
|
||||
Reference in New Issue
Block a user