日志

有用的日志设计，应当从一个能够准确翻译为查询的问题开始。“找出错误记录”与“统计协调世界时十点到十一点之间最终失败的结账请求数”并不是同一个问题。前者用于定位诊断事件，后者需要明确哪些已完成请求属于总体、什么结果算失败，以及时间如何归属。单纯收集更多文本，并不会自动补齐这些语义；如果问题本身模糊，增加字段和存储量也可能只是让错误计算更快出现。 对于请求结果问题，可以定义每个逻辑请求只产生一次的终态事件。需要排查重试时，另外保留尝试事件，并为每个事件赋予稳定身份，以便识别重复投递。请求编号负责连接一次请求中的多个事件，事件编号负责区分这些事件本身。如果把请求编号用作所有事件的去重键，就会把合法的多次尝试和最终结果一起折叠掉，丢失原本需要解释的处理过程。 让查询约定可以被看见 首先决定窗口依据事件发生时间还是日志到达时间。采集器延迟时，两者会明显不同。采用包含起点、不包含终点的半开区间，可以让相邻窗口首尾连接，而不重复计算恰好落在边界上的事件。比较之前，还要把时间归到明确且无歧义的基准。只有本地时钟文字而没有偏移信息，不足以证明一条记录属于某个 UTC 故障窗口，不能由查询人员临时猜测其含义。 随后定义哪些终态属于失败。服务端错误、客户端取消和输入被拒绝，未必适合放进同一个可靠性指标。还应说明相关请求是否都会产生终态事件，以及采集链路是否可能丢失记录。查询对数据库里现存事件完全正确，也仍然可能无法完整描述服务行为。保留期限和筛选策略应写在结果解释旁边，不能只藏在采集配置里，让图表读者误把部分记录理解成全部业务事实。 坏掉的样子 一个请求第一次尝试失败、重试后成功，会留下真实错误事件，但它不是最终失败请求。把每条错误日志都计入失败请求数，会夸大问题；重复投递又可能把同一错误再计算一次。去重应建立在事件身份不可变的约定上。如果两个不同内容声称拥有相同事件编号，那是数据完整性异常，不能因为去重查询能顺利运行，就认为随便忽略其中一个也不会影响结果。 空窗口会带来另一种误判。零个失败除以零个请求，并不是已经测得零失败率。必须保留没有分母这一事实，否则日志采集停止时，可靠性图表反而可能显得十分健康。当排查需要解释某个具体请求时，应在总体口径确定后，读取该请求按时间排列的事件和依赖细节。单独一个汇总数量无法说明哪次重试恢复了，也无法解释另一个请求为什么最终失败。 快速验证 将代码保存为 log-questions.py，用 Python 执行。本次实际环境为 Python 3.14.4，使用标准库中的 SQLite 模块和内存数据库。输入的八条投递记录里有一条完全相同的重复事件；时间围绕一个固定 UTC 小时构造，并专门包含窗口开始之前的一条记录，以及恰好发生在窗口结束时的一条记录。这里没有连接真实采集器或外部数据库，目的是把查询规则及边界结果精确展示出来。 import json import sqlite3 from datetime import datetime def timestamp(value): parsed = datetime.fromisoformat(value) assert parsed.tzinfo is not None return int(parsed.timestamp()) start = timestamp("2026-09-01T10:00:00+00:00") end = timestamp("2026-09-01T11:00:00+00:00") rows = [ ("e0", "r0", "request.completed", start - 1, 503), ("e1", "r1", "attempt.failed", start + 600, 503), ("e2", "r1", "request.completed", start + 660, 200), ("e3", "r2", "attempt.failed", start + 900, 503), ("e4", "r2", "request.completed", start + 960, 503), ("e4", "r2", "request.completed", start + 960, 503), ("e5", "r3", "request.completed", start + 1080, 200), ("e6", "r4", "request.completed", end, 503), ] db = sqlite3.connect(":memory:") db.execute("""CREATE TABLE events ( event_id TEXT PRIMARY KEY, request_id TEXT, event_type TEXT, occurred_at INTEGER, status INTEGER)""") db.executemany("""INSERT INTO events VALUES (?, ?, ?, ?, ?) ON CONFLICT(event_id) DO NOTHING""", rows) stored = db.execute("SELECT count(*) FROM events").fetchone()[0] assert stored == 7 error_events = db.execute("""SELECT count(*) FROM events WHERE occurred_at >= ? AND occurred_at < ? AND status >= 500""", (start, end)).fetchone()[0] query = """SELECT count(*), coalesce(sum(status >= 500), 0) FROM events WHERE event_type = 'request.completed' AND occurred_at >= ? AND occurred_at < ?""" total, failed = db.execute(query, (start, end)).fetchone() completed = db.execute("""SELECT request_id, status FROM events WHERE event_type = 'request.completed' AND occurred_at >= ? AND occurred_at < ? ORDER BY request_id""", (start, end)).fetchall() assert completed == [("r1", 200), ("r2", 503), ("r3", 200)] assert (error_events, total, failed) == (3, 3, 1) empty_total, empty_failed = db.execute(query, (end + 1, end + 3600)).fetchone() empty_rate = empty_failed / empty_total if empty_total else None assert (empty_total, empty_failed, empty_rate) == (0, 0, None) print(json.dumps({"received_events": len(rows), "deduplicated_events": stored, "error_events_in_window": error_events, "completed_requests": total, "failed_requests": failed, "terminal_failure_rate": failed / total, "empty_window_rate": empty_rate}, indent=2)) db.close() 去重之后应剩下七个独立事件。在窗口内，按状态宽泛检索会找到三个错误事件：第一个请求的一次失败尝试、第二个请求的一次失败尝试，以及第二个请求的失败终态。但只统计终态时，结果是三个已完成请求，其中一个失败。第一个请求重试后成功，第三个请求直接成功，位于窗口外和结束边界的事件都被排除。因此请求最终失败比例是三分之一，而不是错误事件数除以某个未经定义的总量。 ...