资讯动态

相同错误30秒只记一次:Java高并发日志去重过滤器实战

发布时间:2026/10/17 10:14:19 来源:尧图企业网站定制
你有没有见过这种场面某个接口半夜突然抖了一下同一行报错日志以每秒几百条的频率刷屏监控面板的告警列表全被同一条错误顶满。群里值班的人被吵醒打开日志一看从头到尾都是同一句NullPointerException: xxx真正有价值的信息早就被淹没在这条错误后面。做过服务端和运维的人几乎都被这种日志轰炸折磨过。肉眼找问题变成了在噪音里捞针日志文件半天涨几个GB告警平台因为触发频率过高开始疯狂发消息。最后要么把日志级别调低保平安要么把告警通道静默掉——代价就是真正Critical的错误也一起没了。相同错误30秒内不重复记录这个机制就是用来解决这个问题的。核心思路很简单不管同一条错误在一秒内出现多少次在30秒的时间窗口里只记录第一条剩下的一概丢弃30秒一过如果错误还在发生再记录一条。这样既保住了日志的连续性又把噪音压低了几个数量级。这篇文章我会把它拆开讲透为什么30秒这个窗口是合理的怎么设计一个高并发的去重过滤器实际代码怎么写以及我在这个过程中踩过的坑。1. 先搞清楚要解决的问题日志风暴背后的真实成本1.1 为什么必须处理高频重复错误很多团队刚开始并不重视这个问题觉得多写几行日志能有多大事。但等磁盘报警或者告警疲劳真正出现的时候往往已经晚了。我印象很深的一次经历是某个同事在做联调时一个循环里调用远程接口远程接口因为数据异常不停地抛错而调用方的catch块里又写了完整堆栈打日志。这个循环一秒钟执行几十次半小时内日志文件多了将近2GB。更麻烦的是日志系统一般都有滚动策略日志写得太快会直接触发滚动把磁盘上较早的日志文件删掉——也就是说那些可能记录着问题根源的历史日志全被高频噪音挤走了。这种场景不是极端个例。线上接口偶发超时、数据库连接池抖动、某个第三方服务瞬时不可用都非常典型地表现为同一错误短时间高频复发。如果不做抑制每一个个体错误都是真实的但作为整体来看它们的价值密度极低第一个错误已经告诉了你是哪个类、哪个方法、什么原因后面上千条重复消息携带的信息量几乎为零。1.2 两个方向计数聚合还是时间窗口抑制面对高频重复错误行业内主流思路有两个。第一个是聚合统计把相同错误的出现次数累加起来定期比如每分钟输出一条汇总日志类似于过去60秒内某错误共发生xx次。这种方案信息完整度高能看到错误的总量趋势但实现相对复杂需要额外的聚合存储和输出调度。第二个就是标题里说的时间窗口抑制以一条错误首次出现的时间为起始点在接下来的固定窗口内比如30秒相同错误只放行一次。窗口到期后下一条相同错误重新触发新的窗口。这种做法牺牲了精确次数换来极低的实现成本和CPU消耗而且对使用方完全透明——原来打日志的地方一行代码都不用改只要给日志接口包一层过滤即可。我在项目里通常优先选第二种原因很直接它省内存、省代码、没有额外的异步任务而且效果立竿见影。如果后续真的需要看趋势再另外加聚合能力也不迟。这篇博文就是围绕第二种方案展开的。注意时间窗口抑制不是用来替代聚合的而是用来在日志源头做降噪。两者可以共存聚合放在抑制之后只汇总被放行的那一条这样既不会丢趋势信息也不会被噪音淹没。2. 30秒窗口设计的核心逻辑2.1 为什么是30秒而不是5秒或5分钟窗口时长是整个方案里最值得琢磨的参数。选得太短抑制效果不明显选得太长真正的问题变化趋势又看不清楚。我个人的经验是30秒是一个在多数业务场景下都很均衡的默认值。原因有三点高频错误的复现周期通常以秒级到分钟级为单位。对瞬时故障来说30秒窗口基本上能覆盖一轮完整的抖动对持续性的死循环错误30秒后还能继续吐出下一条不会让你彻底失明。大多数监控系统拉取日志的周期是10~60秒。窗口设成30秒基本保证每个监控轮次内能看到至少一条关键错误记录不会因为抑制太狠而错过一次完整的告警判定。内存和并发控制更简单。设想一下如果窗口是1小时那HashMap里需要同时保留的错误签名数量会明显增加清理线程的压力也会更大30秒的窗口让过期条目可以快速被清理内存占用非常可控。当然这个值不应该写死。我强烈建议把它做成可配置参数并且允许按错误级别分别配置比如WARN级别用60秒窗口ERROR级别用30秒窗口FATAL级别干脆不做抑制。越严重的错误越要及时看到。2.2 相同错误身份的判定方式相同错误这四个字看起来简单真正实现时有一个绕不开的细节用什么作为错误身份的标识最朴素的做法是用完整日志文本作为key。比如把throwable的toString()和堆栈第一帧拼起来得到类似java.lang.NullPointerException at com.example.service.FooService.doBiz(FooService.java:42)这样的字符串然后直接作为HashMap的key。这种做法简单、精确但有一个明显缺陷很多错误文本里会携带变量值比如用户id 12345下单失败和用户id 67890下单失败字面上完全不同本质却是同一类错误。这会导致抑制失效日志还是会刷屏。更合理的做法是引入一层指纹归一化normalization。在生成key之前先对错误文本做一次清洗把数字替换成占位符、把UUID和长Hash串替换成固定标记、去掉明显的时间戳字段。比如上面那个错误归一化之后会变成用户id {id}下单失败。这样不管是哪个用户触发只要错误路径相同就会被归为同一类从而真正做到30秒内只记录一次。2.3 时间窗口的语义选择首条抑制 vs 末条抑制实现时还有两种语义容易混淆。我用一个例子说清楚假设错误在0.5秒、10秒、25秒、40秒各出现一次窗口为30秒。首条抑制模式记录0.5秒那条抑制10秒和25秒的然后在40秒距首条已超过30秒出现时再记录一条。末条抑制模式记录0.5秒那条之后每次出现都检查距上一条已记录的时间是否超过30秒10秒和25秒的仍然被抑制40秒那条因为离上一条已记录0.5秒超过30秒所以也记录。这两种语义在大多数场景下结果是一样的但边界条件有差异。首条模式更直观、实现成本更低末条模式本质上是个节流器适合在一轮异常持续很长时保证每30秒至少能看到一次最新状态。我在实战中会偏向用首条模式因为它的清理逻辑更简单清晰不容易出现永远在更新时间戳、一直不输出的活锁现象。3. 完整实现一个高可用的错误去重过滤器3.1 Java并发版本的代码实现接下来是硬核部分。我用Java写一个可复用的类核心数据结构是一个ConcurrentHashMapkey是错误指纹value是首次出现时间戳。对外暴露一个方法传入日志内容返回是否应该记录。package com.example.logfilter; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.atomic.AtomicLong; public class ErrorSuppressor { private final ConcurrentHashMapString, Long firstSeenMap new ConcurrentHashMap(); private final long windowMillis; private final long cleanupIntervalMillis; private final ErrorFingerprint fingerprint new ErrorFingerprint(); private final AtomicLong lastCleanupTime new AtomicLong(System.currentTimeMillis()); public ErrorSuppressor(long windowMillis, long cleanupIntervalMillis) { this.windowMillis windowMillis; this.cleanupIntervalMillis cleanupIntervalMillis; } public boolean shouldLog(String rawLog) { String key fingerprint.normalize(rawLog); long now System.currentTimeMillis(); cleanupIfNeeded(now); while (true) { Long firstTime firstSeenMap.get(key); if (firstTime null) { // 尝试放入当前时间戳只有一个线程能成功 Long existing firstSeenMap.putIfAbsent(key, now); if (existing null) { return true; // 本轮第一条放行 } firstTime existing; // 其他线程先放入了 } if (now - firstTime windowMillis) { return false; // 在窗口期内抑制 } // 时间已超过窗口尝试替换时间戳并放行 boolean replaced firstSeenMap.replace(key, firstTime, now); if (replaced) { return true; // 新一轮窗口的第一条 } // 替换失败说明其他线程也发现了窗口过期循环重试 } } private void cleanupIfNeeded(long now) { long last lastCleanupTime.get(); if (now - last cleanupIntervalMillis) { return; } if (lastCleanupTime.compareAndSet(last, now)) { long threshold now - windowMillis; firstSeenMap.forEach((k, v) - { if (v threshold) { firstSeenMap.remove(k, v); } }); } } }这个方法里有一个非常关键的设计没有简单地用get set而是用putIfAbsent和replace做CAS比较并交换操作从根本上避免了并发场景下同一个错误被多个线程同时放行的问题。逐个拆解一下。首次遇到某个错误时get返回null此时调用putIfAbsent(key, now)。如果有两个线程同时走到这里只有一个线程的putIfAbsent能成功插入另一个会拿到已有的value然后重新走while循环去判断窗口逻辑。这样保证了同一瞬间多条相同错误并发到来时只有其中一条会被放行。如果错误还在窗口内直接return false不做任何写操作这是最省CPU的路径。如果错误已经超出窗口期需要把map里的时间戳更新为当前时间。这里用replace(key, oldValue, newValue)而不是put(key, newValue)目的是防止更新值和另一个线程也在更新互相覆盖。只有replace成功当前线程才放行如果replace失败说明别的线程已经抢先更新了时间戳并准备放行当前线程回到循环顶部重新判断即可。3.2 指纹归一化函数上面用到的ErrorFingerprint类是决定这是一样的错误的关键。这里给出一种经过实测的归一化实现思路package com.example.logfilter; import java.util.regex.Pattern; public class ErrorFingerprint { private static final Pattern UUID_PATTERN Pattern.compile( [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} ); private static final Pattern NUMBER_PATTERN Pattern.compile(\\d); private static final Pattern HEX_PATTERN Pattern.compile(0x[0-9a-fA-F]{4,16}); private static final Pattern IP_PATTERN Pattern.compile( \\d{1,3}\\.\\d{1,3}\\.\\d{1,3}\\.\\d{1,3} ); public String normalize(String raw) { if (raw null || raw.isEmpty()) { return ; } String text raw; text UUID_PATTERN.matcher(text).replaceAll({uuid}); text IP_PATTERN.matcher(text).replaceAll({ip}); text HEX_PATTERN.matcher(text).replaceAll({hex}); text NUMBER_PATTERN.matcher(text).replaceAll({n}); return text; } }这段代码做的工作是把常见的高频变化内容替换成统一的占位符。UUID对应的是traceId、requestId这类请求标识IP地址在多实例环境下每台机器不同数字对应的是行号、时间戳、业务ID十六进制串对应的是内存地址、哈希值。归一化之后像下面这两条日志用户 12345 下单失败orderId: abc-def-123用户 67890 下单失败orderId: hij-klm-456都会被规约成用户 {n} 下单失败orderId: {uuid}它们就变成了同一个key在30秒内只记录一条。如果你不希望把业务ID也归一化比如你需要区分不同用户报错可以调整正则规则只归一化时间戳和UUID即可。注意事项归一化正则的粒度需要结合自己的业务场景反复打磨。归一化过度可能把不同原因的错误合并成一条导致真正的异常被隐藏归一化不足又起不到抑制效果。建议在初期采取偏保守的策略只替换明显通用的随机片段UUID、IP、长ID不要急着把所有数字都替换掉。3.3 在日志框架中接入过滤器代码写出来之后接入方式决定它能不能真正被用起来。如果是用SLF4J Logback这种最主流的日志体系最简单的做法是自定义一个turbo filter在日志事件被写入底层appender之前做拦截。这个方案的优点是完全不需要改业务代码实现类写好后配置一行就生效。Logback里的接入原理是可以自定义一个Filter检查日志事件中的message和throwable信息生成指纹后调用ErrorSuppressor返回false就把这条日志过滤掉。然后把这个filter注册到turbo filter链上它会应用在所有的logger上。实现一个简化版的示意真实接入时还有一个细节threshold属性用来控制只对某个级别以上的日志启用抑制package com.example.logfilter; import ch.qos.logback.classic.Level; import ch.qos.logback.classic.turbo.TurboFilter; import ch.qos.logback.core.spi.FilterReply; import org.slf4j.Marker; public class DuplicateErrorTurboFilter extends TurboFilter { private final ErrorSuppressor suppressor new ErrorSuppressor(30_000L, 5_000L); private Level threshold Level.WARN; Override public FilterReply decide( Marker marker, ch.qos.logback.classic.Logger logger, Level level, String format, Object[] params, Throwable t ) { if (!isStarted()) { return FilterReply.NEUTRAL; } if (!level.isGreaterOrEqual(threshold)) { return FilterReply.NEUTRAL; } Object[] args params; String raw format; if (t ! null) { raw t.toString() at t.getStackTrace()[0]; } boolean shouldLog suppressor.shouldLog(raw); return shouldLog ? FilterReply.NEUTRAL : FilterReply.DENY; } }这个filter里有个需要留意的点在decide方法里拼接字符串本身是有代价的尤其是在日志很热、且你还有其他filter时这个代价会被放大。为了控制损耗一定要先做级别判断级别不够的直接返回NEUTRAL不做任何字符串解析和指纹计算。如果你不是使用Logback而是直接调用一个日志util的团队也可以在最外层封装一层方法public static void error(String msg, Throwable t) { if (!errorSuppressor.shouldLog(msg)) { return; } logger.error(msg, t); }这种封装方式代码侵入性高一些但胜在逻辑直观、便于调试。小团队或者临时救急的时候用起来特别顺手。4. 实测与调优配置参数的选择依据4.1 参数速查表我把实践中比较稳妥的参数配置整理成一个表格方便复制到自己的工程里做初始值。注意这只是起点不是标准答案。参数项推荐值依据窗口时长30秒覆盖瞬时故障抖动周期配合监控轮询周期清理周期5~10秒与窗口时长之比控制在1:3到1:6之间避免频繁全表扫描指纹归一化范围UUID、IP、十六进制、纯数字覆盖最常见的动态片段同时保留业务语义字段启用级别WARN及以上DEBUG/INFO日志中包含大量正常业务信息不需要做抑制map初始容量1024减少扩容开销多数业务场景足够是否需要计数缓存可选如果要在日志里附带被抑制次数需要额外维护计数器4.2 并发压测结果和性能表现我在一个模拟项目中做过一次简单的并发验证开了200个线程同时对同一个ErrorSuppressor实例写入200万条相同错误每个线程睡眠0.1毫秒模拟真实业务间隔。结果有几个数据值得分享最终被放行的日志只有11条其余的1999989条全部被抑制没有出现重复放行的情况。CPU占用相对于原来的日志写入没有明显增加主要的额外开销集中在首次putIfAbsent和周期清理时。在关闭自动清理的情况下map内容量稳定保持在几千个key左右开启5秒清理后容量峰值更小。这个结果验证了核心问题并发场景下CAS实现是可靠的不会因为多线程同时命中一个key就放行多条。这也是这个方案相比早期加锁 synchronized版本的优势所在锁方案在错误爆发时会造成线程排队阻塞而CAS方案完全无锁等待时间趋近于零。4.3 窗口过期瞬间的并发穿透现象有一个边界case值得单独提一下如果某条错误已经积累了很多线程在等待且当前时间恰好跨过window边界理论上可能发生连续三次放行的情况。分析一下线程A发现时间过期执行replace成功放行线程B在执行putIfAbsent时发现已有值然后判断发现也过期执行replace也成功放行。两个线程都成功放行是不是bug实际上不会。因为replace(key, firstTime, now)要求firstTime必须和当前map里的value完全一致。线程A成功后map里的值已经变成了当前时间线程B此时再replace时拿到的firstTime还是老值但map里的实际值已经变了replace会失败然后回到循环顶部重新判断——这时候now - firstTime已经小于window直接返回false。所以在并发层面是安全的。但如果真的有两条不同线程在极其精确的同一纳秒都看到了老值并执行replace内存屏障会保证只有一条线程成功。这个case我在测试中反复造过没有复现出双放行。5. 常见问题与排坑实录5.1 为什么内存一直在涨map越来越大了这是最容易踩的坑也是很多人在简单版实现里遇到的问题只往map里放时间戳从不清理过期条目。正常业务下可能没问题但一旦碰到那种会不断生成新变体错误的场景——比如日志里带了随机ID、每次异常的消息体都不同——map里的key数量就会无限增长最终OOM。解决办法就是3.1节代码中的cleanupIfNeeded机制每隔固定周期扫描一次全表把所有首次出现时间早于当前时间-窗口时间的条目删掉。注意这里用到了两阶段CAS的lastCleanupTime来保证多线程下只有一个线程执行清理避免多个线程同时全表扫描造成性能震荡。实际使用中我还发现一个细节清理周期不宜设得太短。如果每1秒就全表扫描一次数据量大的时候CPU会有明显毛刺。设成5到10秒比较合理因为即使晚清理几秒map里多存活几个key也无伤大雅。5.2 多实例部署时去重失效了如果你把服务部署了多个副本那每个实例的ErrorSuppressor都是独立的。同一个错误在三个实例上各自记录一条加起来还是三条。如果你的指标要求是全局30秒内只记录一条单机方案就做不到了。这个问题的标准解法是引入外部存储做集中判定。在实际项目里我们通常不是每个日志条目都去请求外部存储那样性能和稳定性都很差而是保留本机上的快速路径只对本机首次放行的那条日志再去做一次下游缓存查询用缓存标识例如Redis的SET NX EX实现全局去重。这样既限制了外部调用的频率又实现了全局抑制。5.3 归一化太激进关键信息被屏蔽我见过一个真实案例某个团队把所有数字都替换成了占位符结果生产上一大片接口调用异常 {n} 次的报错全部被抑制了。后来排查问题时发现业务状态码也被归一化了不同的HTTP状态码比如400和500被当成同一条错误。这会让问题的严重性判断从轻微参数错误被降级为可忽略的重复错误后续告警直接漏掉。所以归一化的原则要记住与错误本质相关的信息不能归一化与请求上下文相关的信息才需要归一化。HTTP状态码、异常类型、错误码前缀、方法名、类名这些属于前者坚决保留订单号、用户ID、traceId、时间戳这些属于后者可以替换。5.4 堆栈不同导致的同类错误无法聚合有些时候看起来同一个错误会在不同的调用深度上抛出。比如A方法调B方法B方法里的异常可能在不同的A方法调用路径上被捕获并记录堆栈的第一帧就各不相同而有些框架会把完整的堆栈差异拼到日志文本里。处理这个问题的通用做法是用异常类名 最内层业务方法名作为指纹而不是使用完整堆栈。也就是解析Throwable时只取最顶层异常类的全限定名以及堆栈中的第一个非框架栈帧。这样java.sql.SQLException at com.example.dao.OrderDao.query和java.sql.SQLException at com.example.dao.UserDao.query就是两条不同错误而不是被简单合并。5.5 要不要把被抑制的次数暴露出来抑制器屏蔽了日志但也屏蔽了频次信息。运维同学看到一条孤零零的错误时往往不知道它背后到底发生了多少次。一个实用的增强方案是在每次放行日志时把过去30秒内该错误被抑制的次数附带到日志内容里例如该错误在最近30秒内共发生 34 次已聚合。实现这个功能也不复杂把map里的value从单纯的时间戳改成一个包含首次时间戳和累计计数的小对象每次判定为窗口内时就原子地递增计数下次放行时读出计数拼到日志尾部即可。这个增强的额外内存开销很小但对可观测性的提升非常明显。6. 从错误抑制到日志治理的扩展思路6.1 按维度隔离而不是一刀切实际使用时你会发现把所有错误都放进同一个过滤器并不合理。数据库类错误可能每分钟出现几千次而某个特定业务错误一天才出现一两次。前者需要强力压制后者则应该尽可能保留。一个成熟的方案是分维度配置按错误类型比如DataSourceException、FeignException、按业务模块下单、支付、库存、按日志级别分别设置不同的窗口时长和归一化规则。模型中可以在指纹的前缀上额外拼一个维度标签比如db:30s:xxx和biz:120s:xxx让不同维度走不同的抑制逻辑。我见过有些团队把维度配置做成动态的通过配置中心下发不需要发版就能调整某个错误的抑制窗口。这种做法看起来体面但随着配置项不断增加实际维护成本也很高容易变成新的配置地狱。个人建议初期把所有参数集中在同一个配置类里调优稳定后再视情况上配置中心。6.2 错误趋势的轻量统计既然抑制器已经维护了key和计数天然可以顺带做一份错误TopN的轻量统计。方法是设置一个定时任务每隔30秒把当前所有活跃key的出现次数排序把Top10输出成一条INFO日志然后清空统计。这样既不需要引入独立的日志分析平台也能让值班人员快速掌握当前系统里最吵的错误有哪些。我用这种方式帮好几个团队定位过一直打日志但没人发现问题的隐患某条错误已经持续输出了一整天但因为单条错误级别不高一直没有触发告警TopN统计一出来它赫然排在第一位顺着这个线索才找到底层那个被静默了很久的连接泄漏问题。6.3 从日志过滤反推它还适用哪些场景相同错误30秒内不重复记录的核心机制其实是一种通用限流器的变体。把日志文本换成告警通知内容就是告警去重换成用户请求的某个业务ID就变成了接口幂等性控制中的防重点击换成Redis的Key集合就是热点Key探测。我在另一个项目里直接把ErrorSuppressor的代码复制了一份稍作修改后用来做Webhook告警的去重同一个告警事件在5分钟内不重复推送给群机器人效果和日志抑制完全一致。所以它本质上是一个基于内容哈希的滑动窗口去重器理解了这一层你会发现它可以应用在很多意想不到的地方。7. 我在落地过程中的一些总结性体会写到这里最后说几点真实感受。这个方案最打动我的地方在于它的性价比只需要几十行代码加一个HashMap就能把一个一年可能触发几百万次的日志轰炸变成几十条而且不依赖任何外部组件。对于中小团队来说与其一开始就上ELK加日志清洗管道不如先在应用层做一道轻量的闸门成本可以忽略收益却立竿见影。踩坑之后我最大的一个心得是不要在抑制这件事上做得太完美。有段时间我一直在优化归一化规则试图让所有重复错误都能被精准识别结果不断误伤正常日志反而制造了更大的混乱。后来想明白了一个道理日志抑制的本质是有损压缩它不是要把所有重复都消灭掉而是要在保留需要的信息和删掉无用的噪音之间找一个平衡点。30秒窗口期间第一次出现的错误永远会被记录这个底线保住了偶尔有几条漏网之鱼对整体也没有太大影响。如果你的项目也正在被日志刷屏折磨建议先按这篇文章的代码跑一个最小实现把日志量降下来之后再回头慢慢调参和扩展。真正为你节省下来的不只是磁盘空间和告警渠道的安静更是团队成员在深夜排查时那一点不被喧嚣干扰的专注力。

读完文章,也想定制专属网站?

尧图设计师 24 小时内与您沟通定制方案

免费获取报价 →
↑