早年间我维护过一套内部 API 服务每次发版后翻日志最崩溃的不是报错多而是同一个错误刷屏几百行千篇一律的堆栈把真正的新异常完全淹没。后来我给自己写了个小工具代号就叫 REA——Recurring Event Analyzer。它的核心功能只有一句话把周期性重复出现的错误事件自动聚合成摘要再按指纹、时间、趋势告诉你“这类问题又来了”。这篇文章记录的就是我从零做 REA 的整个过程包括为什么这么设计、核心代码怎么写以及实测时踩到的那些坑。如果你手头也有一堆日志要处理或者被重复告警折腾到想砸电脑这篇文章应该能给你几个直接能抄的思路。我不会讲那种要搭三个组件才能跑起来的大而全方案只讲我自己在本地从脚本迭代到小工具的真实过程。你不需要 Kubernetes不需要大数据平台一台普通开发机就能复现整个方案。1. 重复日志是报警疲劳的根源不解决它排查就是大海捞针1.1 一个再常见不过的故障现场事情发生在一次常规发布之后。某内部服务的支付回调接口突然超时监控页面一片飘红但大家盯着日志系统看了半天愣是没找到根因。原因很无厘头一个很老的空指针异常在某个线程里疯狂重试每分钟刷出上千条相同堆栈把真正导致超时的连接池耗尽日志完全压到了后面。当时我统计了一下那段时间日志总量里重复内容占了 87%。也就是说如果能把重复日志先聚合整个排障效率至少提高五倍。可惜当时的告警系统只会机械地数条数相同的异常每来一条就发一次通知值班手机震得像按摩仪。所有人都知道问题存在但没人能快速定位问题到底长什么样。这就是典型的“报警疲劳”不是没有日志不是没有告警而是告警太多、重复度太高人的注意力被稀释掉之后真正重要的信号反而被无视了。REA 诞生的初衷就是解决这个被大多数人忽略的痛点——与其增加更多监控指标不如先把已有日志里的“信息熵”提上来。1.2 REA 的目标让“同类问题”自动闭嘴和归档在动笔写代码之前我给自己定了三条硬目标后面所有设计都是围绕它们展开的。第一条同类合并。同一时间窗口内如果出现了 N 条日志它们的核心错误信息一致只是时间戳、随机端口号、内存地址这些无意义字段不同那它们必须被归并成一条摘要而不是三条。第二条静默降噪。当某个错误第一次出现时可以立刻提醒但当它在短时间内反复出现后续提醒必须变成“该错误已经发生 X 次状态持续中”而不是每来一条就重新响一次。第三条可回溯。聚合之后的每条摘要必须能根据指纹快速找到原始日志样本。不能为了压缩而彻底丢失细节否则排查时依然要返回原始日志系统里去大海捞针。围绕这三条可以推导出 REA 的基本形态一个读取日志流计算指纹按时间窗口聚合并输出降噪事件的轻量服务。它不负责存储大量原始日志也不用关心分布式链路只做一件事把日志流变成高价值的事件流。1.3 为什么不用现成方案可能有人会问日志聚合不是有现成工具吗什么日志平台、错误追踪服务早就有类似能力。我也不是没考虑过直接引入一个重型方案但最后因为两个原因放弃了。第一现有工具的指纹算法往往是黑盒。它们更擅长按“异常类型堆栈哈希”来分组但我在实际使用中看到过不少误分场景同一个错误因为 URL 路径中的 ID 不同被分成了上百个 group又或者两个不同的错误因为堆栈第一帧相同被合并到了一起。对于我这种想精确控制指纹规则的场景黑盒方案很难满足。第二很多平台的部署成本和学习成本都很高。为了一个小小的日志聚合需求去维护一套完整的日志采集-处理-存储链路不值当。我更想要的是一个自己能完全看懂、能随时改逻辑、能在单机上一行命令跑起来的轻量工具。于是就有了 REA。它本质上是一个“日志事件预处理器”放在日志系统前面做降噪清洗吃的是标准输入或文件流吐的是聚合后的 JSON 事件。这不是一个多惊艳的架构但足够解决我当时的核心问题。2. 先把架构想清楚REA 的输入、处理、输出三件套2.1 输入侧日志流怎么进任何日志处理工具的起点都是“日志从哪里来”。我给 REA 设计了两种输入方式分别应对不同阶段的需求。第一种是文件回放模式。把一段完整的日志文件喂给 REA让它从头到尾跑一遍输出聚合摘要。这种模式适合事后复盘线上出了事故把日志导出本地跑一下 REA立刻能得到问题分类清单。第二种是实时流模式。通过标准输入接住上游进程的输出或者通过简单的 HTTP 回调接收日志行REA 边进边出持续产出事件流。在输入侧有一个非常容易被忽略的点日志行未必是一行一次事件的。多行堆栈Java 的 stack trace、带时间戳的连续片段都会被拆成多行。所以在做指纹之前必须先做“多行合并”把属于同一次异常的连续行拼接成一条完整事件。我实现了一个非常朴素的状态机如果某一行以时间戳或异常类型开头就开启一个新事件如果后续行是空白或缩进行就追加到当前事件。这个设计对后续指纹准确性特别关键。因为堆栈的第一帧往往是最有价值的信息如果把上面的业务信息行和下面的堆栈帧拆开聚合就没有意义了。2.2 处理侧指纹、分桶、状态机处理侧是 REA 的心脏。我用三个组件来描述它指纹器、窗口桶、状态机。指纹器负责把规范化后的事件消息转换成一个固定长度的哈希值。我选择的是 SHA-1 的十六进制摘要指纹相同就代表“这是同一类问题”。为什么不选 MD5因为在这个场景里密钥长度不重要反而更在意碰撞概率。虽然它们都是哈希但 SHA-1 的分布更均匀一点而且使用起来没有额外的命名包袱。窗口桶是时间维度上的容器。我默认采用 60 秒的滑动窗口窗口内的所有事件按指纹聚合。每个桶里维护一个字典key 是指纹value 是窗口内的计数器。滑动窗口意味着一条事件进入时既属于当前窗口也往下衰减进入后续窗口从而避免“卡点”效应。状态机则决定了每个指纹的生命周期。一条新指纹进入后状态为NEW当它在同一个窗口内重复出现且超过阈值状态变为FIRING如果后续窗口没有该指纹的新事件状态变为RECOVERED。只有状态发生切换时REA 才对外输出事件这样就起到了“抑制重复告警”的效果。2.3 输出侧聚合事件和抑制规则REA 的输出是干净的 JSON 数组每条输出至少包含指纹、原始事件样例、出现次数、首次时间、最后时间、状态变化。我把输出设计成两种模式标准输出人眼友好和回调端点机器友好。调试的时候直接看终端接入告警平台时就用回调。抑制规则是整个方案的灵魂。我并没有一刀切地屏蔽重复日志而是用一个阈值开关来控制。比如设定窗口阈值 10 次同一个指纹在 60 秒内首次出现时立即输出一条NEW事件当计数器第一次突破 10 时输出一条FIRING事件之后哪怕再有 1000 条相同日志REA 也只会静默更新计数器不再对外喊叫。只有当它真正停止出现一段时间后再输出RECOVERED。这个规则建立在我对告警系统的理解上告警的价值在于状态变更而不在于数量重复。真正需要人关注的时间点是“这个问题出现了”和“这个问题解决了”中间的“又多了 100 次”只是噪音。3. REA 的实现细节核心代码拆给你看3.1 规范化与指纹生成日志文本里藏着很多无意义的随机字段。比如一个订单 ID一个 IP 端口一个 JVM 堆栈里的内存地址。如果直接拿原文做哈希同一个错误会因为具体参数不同而分到不同的桶里等于没聚合。所以我在生成指纹前先做了一次规范化剥离。核心思路是把明显是数字、UUID、IPv4、十六进制地址、时间戳的片段替换成固定占位符。实现起来也不复杂几个正则就能搞定。import hashlib import re _UUID_RE re.compile(r[0-9a-fA-F]{8}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{12}) _HEX_ADDR_RE re.compile(r0x[0-9a-fA-F]{4,16}) _INT_RE re.compile(r\b\d{2,}\b) _IP_RE re.compile(r\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}) def normalize_event(raw_text: str) - str: text raw_text.strip() text _UUID_RE.sub(uuid, text) text _HEX_ADDR_RE.sub(addr, text) text _IP_RE.sub(ip, text) text _INT_RE.sub(int, text) # 统一空白 text re.sub(r\s, , text) return text def make_fingerprint(event: str) - str: normalized normalize_event(event) # 只取前 2000 个字符做指纹防止超长日志拖慢哈希 sample normalized[:2000] return hashlib.sha1(sample.encode(utf-8)).hexdigest()这里面有一个细节长度截断。某些异常会把完整请求体打出来一行日志可能几万字符。如果不做截断指纹计算会非常耗时而且超长日志中尾部的动态参数对分类并没有帮助保留前 2000 字符足够覆盖错误类型和关键堆栈帧了。3.2 时间窗口聚合器的设计窗口聚合器是 REA 的核心数据结构。我用一个带过期删除的字典来实现而不是简单堆一个无限增长的列表。每个指纹对应一个“桶内计数”和一个“最近活跃时间”。from collections import deque import time class WindowedAggregator: def __init__(self, window_seconds: int 60): self.window_seconds window_seconds self._events deque() self._counters {} def add(self, fingerprint: str, event: str, timestamp: float): # 清理已过期的窗口数据 while self._events and self._events[0][0] timestamp - self.window_seconds: old_ts, old_fp self._events.popleft() self._counters[old_fp] - 1 if self._counters[old_fp] 0: del self._counters[old_fp] self._events.append((timestamp, fingerprint)) self._counters[fingerprint] self._counters.get(fingerprint, 0) 1 def get_count(self, fingerprint: str) - int: return self._counters.get(fingerprint, 0)这个实现的原理是每次新增数据时先把滑动窗口之外的数据从双端队列左侧弹出同时更新计数。这样deque里的数据总量只会维持在一个窗口大小内不会无限增长。双端队列的好处是左侧弹出是 O(1)不像列表的pop(0)那么慢。实际使用中我还会在add里做一次采样保存当计数小于等于 3 时把当前原始事件作为候选样本存下来超过 3 次就停止保存。这样既保留了一条样本用于日后来看又不会让内存被反复出现的同一条日志填满。3.3 告警抑制与衰减有了窗口计数就可以实现抑制规则。我维护了一个指纹状态表记录每个指纹的当前状态和状态切换时间。每个新事件进来后根据当前状态和窗口计数决定是否要输出通知。class AlertStateMachine: def __init__(self, fire_threshold: int 10, quiet_after_fire: int 300): self.fire_threshold fire_threshold self.quiet_after_fire quiet_after_fire self.states {} # fingerprint - (state, last_change_ts) def handle_event(self, fingerprint: str, agg_count: int, timestamp: float): state self.states.get(fingerprint, (NEW, timestamp)) if agg_count 1 and state[0] NEW: self.states[fingerprint] (NEW, timestamp) return {action: notify, level: new, count: 1} if agg_count self.fire_threshold and state[0] in (NEW, RECOVERED): self.states[fingerprint] (FIRING, timestamp) return {action: notify, level: firing, count: agg_count} if state[0] FIRING and timestamp - state[1] self.quiet_after_fire: self.states[fingerprint] (RECOVERED, timestamp) return {action: notify, level: recovered, count: agg_count} return {action: quiet, level: state[0], count: agg_count}这段代码的精髓在quiet_after_fire参数。它的意思是一个错误进入FIRING状态后如果超过 300 秒没有再次出现就认为它恢复了。但即使它恢复后只要再次出现一条就会重新触发NEW因为状态已经从RECOVERED切回去了。这样既不会重复轰炸又不会漏掉故障复发。3.4 配置文件与运行方式我最终把 REA 做成了一个命令行工具配置全部用 TOML 文件也可以是 YAML。核心配置项如下。配置项默认值说明input.modestdin输入方式stdin、file、httpinput.path无文件模式时的日志路径window.seconds60滑动窗口时间长度alert.fire_threshold10触发 FIRING 告警的窗口内次数alert.quiet_after_fire300FIRING 后多久无新事件视为恢复output.formatjson输出格式默认 JSON Linesoutput.webhook无额外推送到 Webhook 地址运行方式很简单实时流模式可以这样跑tail -f /var/log/app.log | python3 rea.py --config rea.toml事后分析模式则直接指定文件跑完就退出python3 rea.py --config rea.toml --input-file app_20241110.log summary.jsonl这两个运行方式覆盖了我 90% 的需求。4. 实测时翻过的车时间窗口边界、内存爆掉、指纹误判4.1 第一个坑自然时间窗口导致跨窗重复报警REA 第一版用的是固定的小时窗口也就是每过整数小时就清空所有计数。上线后立刻发现一个诡异现象某个错误在 11:59:58 出现一次12:00:00 又出现一次逻辑上它们只隔了 2 秒但因为跨了窗口被当成了两个独立的NEW事件告警平台连着响了两轮。我排查的过程是这样的先看输出 JSON发现两条事件的时间戳非常接近但指纹一样。再翻代码发现窗口切换逻辑是“按当前时间取整点”。当时心里就骂了自己一句这显然是经典卡点问题固定边界窗口天生就会有这类跨边界重复计数。解决办法是改为滑动窗口也就是前面代码里那种基于双端队列的实现。滑动窗口的边界不是自然时间零点而是“现在往前推window_seconds秒”。任何一条事件都同时存在于多个相邻窗口的重叠部分但由于计数是按过期时间弹出的不会跨边界重置。这个改动之后跨小时、跨分钟边界的重复事件就彻底消失了。4.2 第二个坑堆栈里的内存地址让指纹完全错位改完滑动窗口后误报率降了不少但漏报率反而升高了。具体表现是同一类异常应该被聚合到一起实际却被分成了几百个不同的指纹。我带了一条实际日志做实验发现堆栈里有大量形如at java.lang.StringBuilder.append(StringBuilder.java:177)这种带行号的内容行号不同本身可以接受。但更隐蔽的是 JVM 在打印某些对象时会带出对象地址比如Object1a2b3c4d或者at 0x00007f8c3a001b28。这些地址每次运行都不同同一个异常消息里只要带一个地址指纹就会完全错位。定位到根因后我给规范化函数加了几条规则。十六进制地址统一替换成addr形如[0-9a-f]{2,}的引用替换成ref所有连续数字替换成int。此外我还加了一条更有用的规则把常见堆栈帧的固定部分类名和方法名提取出来但丢弃括号内的行号与文件名因为不同版本的行号没必要作为分类依据。改完之后同一异常从一个错误分成几十个指纹收敛到了稳定的一到两个指纹。这里我想特别提醒先做小样本验证再上全量。我写了个脚本从真实日志里随机抽 100 条已知同类错误跑指纹算法看聚类纯度达标了才改成正式版本。4.3 第三个坑处理慢导致积压内存先撑不住了聚合器本身是高效的但日志读取和规范化处理是 CPU 密集的。我最初在单线程里既做读取、又做正则替换、又做哈希结果在大日志文件回放时处理速度只有每秒六万行而实际生产日志峰值是每秒三十万行。处理速度跟不上消费速度双端队列就疯狂积压内存直线飙升最后进程被操作系统杀掉。这个坑让我明白了一个道理REA 的第一瓶颈不是存储而是处理吞吐。我随后做了两个改动。第一把规范化函数里的多个正则合并成一次遍历用一个大的正则表达式去搜索所有模式减少了 Python 解释器多次调用re.sub的开销。第二给窗口聚合器加上背压计数器当内部积压事件超过上限比如五万条时停止读取输入三秒让上游管道阻塞一下。这个机制看起来有点粗暴但能确保 REA 宁可拖慢上游也不会把自己搞死。顺便说一下后来我用 Python 的concurrent.futures把规范化函数放进了进程池吞吐从六万提升到了十五万左右。但如果你只是处理普通规模日志单线程加背压就已经够用了不必一上来就上多进程。4.4 排查链路从一个虚假告警倒推根因的完整过程有一次 REA 输出了一个告警指纹abcd1234事件内容是“连接池获取连接超时”但我在原始日志里怎么都搜不到这条异常。这非常奇怪REA 不可能无中生有一定是处理链路里的某个环节把“让”变成了“事件”。我开始倒查。第一步看输出的样例字段里面有raw_sample保存的是原始日志片段。结果发现原始日志其实是Connection pool waiting...根本不是异常只是普通日志。第二步查规范化结果。打开一个 debug 模式打印normalize_event后的字符串发现它是connection pool waiting intms。第三步查指纹来源发现这条普通日志的堆栈第一帧恰好和某个连接池超时异常的堆栈第一帧重合而我在规范化时只取了“前 2000 字符”并没有强制要求消息里包含“exception”或“error”字样导致一条 INFO 日志被错误归到了 ERROR 组的指纹里。根因清楚了我的指纹粒度只看了文本特征没有结合日志级别。同一段代码既可以输出 INFO 日志也可以输出 ERROR 异常它们的消息格式可能一致但含义完全不同。修复方案很简单把日志级别作为指纹前缀的一部分比如error:connection pool waiting intms和info:connection pool waiting intms就是两个指纹。这个排查过程给我的经验是当告警数据与直觉不符时不要急着改告警规则先回看原始样本和中间输出。REA 从一开始就保留了raw_sample字段这一步走得非常正确。否则只能瞎猜。5. 调优笔记窗口大小、阈值、并行度到底怎么配5.1 参数对结果影响的对照实验参数不是越激进越好。我拿一份包含五万条混合日志的样例做了一组对照实验分别调整滑动窗口大小和触发阈值结果如下。窗口大小触发阈值输出事件数误报率漏报率峰值内存10s5134212%2%420MB30s108675%3%460MB60s107433%4%520MB120s306122%9%680MB300s505401%15%900MB一眼能看出来窗口越大、阈值越高输出事件越少但漏报率上升也非常明显。漏报率是什么意思就是“真实发生了新故障但 REA 没有单独通知”因为它和旧故障挤在同一个大窗口里被当成了同类连续事件。我之前常说调参不是在调“正确”而是在调“权衡”。如果你的目标是观察趋势希望少打扰那大窗口高阈值是合理的但如果你要的是及时发现新故障那窗口最好不要超过 60 秒阈值不要超过 10。5.2 并行度设计的取舍Python 写这类工具很难绕过 GIL。我一开始天真地开八个线程做规范化结果 CPU 占用没降反而因为线程切换频繁吞吐反而下降了。后面改成多进程才解决。但多进程带来一个新问题每个进程维护自己的窗口聚合器同一个指纹出现在两个进程里计数就分裂了。于是我只能把“规范化”放到进程池把“聚合”固定在主进程单线程执行。这样每个进程只算哈希主进程统一计数虽然单个聚合线程的吞吐有限但规范化瓶颈被打破之后整体还是能跑到可接受的水平。如果你用的是 Go 或者 Java就没这个烦恼天然的并发模型更好处理。但我的经验是日志聚合的瓶颈往往不在聚合本身而在正则替换和哈希计算上所以合理拆解处理阶段比盲目开线程更重要。5.3 给后来者的参数建议针对不同场景我会给出完全不同的一组初始建议。如果你的服务是低频核心服务每秒日志不超过一万行那直接保持默认窗口 60 秒阈值 5。这样既能快速发现异常又不至于被日常抖动打扰。如果你的服务是高流量网关每秒日志几十万行我会把窗口缩小到 10 秒阈值提高到 100 甚至 1000。因为高流量下同一个错误十秒内就可能出现上千次阈值太低会导致 REA 自己变成新的告警源。还有一个很容易忽略的参数是quiet_after_fire也就是恢复静默时间。如果错误在 300 秒之后又出现一次REA 会把它当作新事件再次通知。这个参数需要跟你的故障恢复时间匹配不要比“单次故障平均恢复时长”还短否则一个故障会被拆成两段告警。6. 如果你也想自己搞一个 REA给你几条实在话这一节不是教程只是我做完 REA 之后的一点个人体会。先想清楚你要解决的问题到底是“重复日志太多”还是“日志格式不统一”。如果说后者REA 帮不了你你得先去推进日志打印的规范化。很多团队把日志分析工具当万能药结果日志里连时间字段都没有工具再强也白搭。不要把第一个版本设计得太复杂。我一开始还想着做自动聚簇、机器学习分类、时序预测后来全部砍掉了。最终真正稳定起作用的核心逻辑加起来不超过五百行代码。你需要的可能只是一个能算指纹、能按窗口聚合、能输出 JSON 的小脚本先跑通再根据实际需求慢慢加。日志标准化的收益比任何算法都大。我在做 REA 的过程中反复体会到“输入侧的脏数据”对结果的影响远大于“处理侧的算法”。如果你能把所有日志统一成时间 级别 服务名 消息体 堆栈的结构那 REA 的指纹准确率可以轻松到 99%。否则你就只能靠正则不停地打补丁。多保留一条原始样本。输出事件里永远带上至少一条原始日志。这项设计在无数次日后的联调中帮了我大忙因为聚合后的摘要再好看真正定位问题的时候还是得回到原始文本。如果你已经有现成的监控告警平台可以让 REA 作为告警源之一接入但要注意幂等性。REA 输出的每条事件都带指纹和时间戳这样下游系统可以根据指纹去重避免重复升级。我最后是把 REA 的输出接到内部值班机器人里由机器人负责去重和升级这样整个链路才算闭环。我自己对 REA 最满意的不是它处理了多少日志而是它让我摆脱了那种“每逢发布必泡在日志里”的窘境。写这个工具前后花了大约一周之后每次需要排查重复告警时我都不需要再盯着屏幕翻滚动条直接看 REA 输出的几张 JSON 摘要就够了。如果你也有同款烦恼不妨从“先给异常日志算指纹”开始试试。很可能你也会发现一个看似不起眼的小工具最后竟然能改变你日常排障的习惯。