使用布谷鸟过滤器对 logback 日志一定周期内重复异常堆栈打印进行压缩过滤

前因

前阵子日子线上有个bug，但是由于触发过于频繁导致日志打印全是这个bug的堆栈，全是重复堆栈内容日志一下变得不友好起来，搜索有没有什么优化办法。

偶然看到[近期业务大量突增微服务性能优化总结-2.开发日志输出异常堆栈的过滤插件]这篇文章，试图将同样的日志堆栈过滤插件复刻到logback中

后来发现堆栈打印还是至少同样的堆栈一天内至少打印一次（日志文件按照天进行拆分）才方便排查，于是就需要判断一个异常的堆栈是否打印过，自然就想到了大名鼎鼎的布隆过滤器和布谷鸟过滤器，遂进行改造

思路

思路是改造ch.qos.logback.classic.pattern.ThrowableProxyConverter ，通过在logback配置中设置日志输出的PATTERN的converterClass 来取代默认的org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter

然后在isIgnoredStackTraceLine方法中加入自定义的过滤逻辑

判断是否重复使用布隆和布谷鸟过滤器

代码及演示Demo

因为有对logback类的copy改造，还涉及到spring环境变量加载和日志系统加载打印的先后关系、日志异常插件自己报异常怎么debug等一堆小坑，代码比较多，建议用的时候可以直接fork改改

这里只看核心的两个方法： 一个是判断该行是否应该被过滤

1. @Override
2. protected boolean isIgnoredStackTraceLine(String line) {
3. //...
4. try {
5. // 具体判断逻辑委托给接口的实现类
6. return predicate.isShouldSkipLine(line);
7. } catch (Exception e) {
8. //...
9. }
10. return super.isIgnoredStackTraceLine(line);
11. }
12.  

一个判断该异常堆栈是否第一次打印，这里使用弱引用key Cache是因为logback对于同一个异常会多次调用这个方法

1. //...
2. @Override
3. public boolean isShouldEnableSkip(IThrowableProxy throwableProxy) {
4. //如果 mightContain false 则直接判断为打印完整堆栈（return false）
5. return Boolean.TRUE.equals(RESULT_CACHE.get().get(throwableProxy, k -> autoRebuildCuckooFilter.isFull(k.getStackTraceElementProxyArray())));
6. }
7. //...
8. public boolean isFull(T item) {
9. //判断是否是新的周期新建过滤器
10. CuckooFilter<T> cuckooFilter = rebuildIfNecessary();
11. //...
12. //交给布谷鸟过滤器或者布隆过滤器来判断是否打印过
13. if (cuckooFilter.approximateCount(item) >= times) {
14. return true;
15. }
16. return !cuckooFilter.put(item);
17. }
18. //...
19.  

使用及效果

如下示例logback配置

1. <?xml version="1.0" encoding="UTF-8"?>
2. <configuration>
3. <!-- 导入spring基础配置 -->
4. <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
5. <!-- 因为覆盖了属性，所以这里不能直接借用 -->
6. <!-- <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>-->
7.  
8. <!-- 替换defaults.xml中定义的属性， 使用自己的噪音抑制异常转换器 -->
9. <conversionRule conversionWord="wEx"
10. converterClass="com.muyuanjin.lognoiseless.NoiseLessThrowableProxyConverter"/>
11.  
12. <!-- 控制台日志，因为覆盖了属性，所以这里不能直接借用 console-appender.xml ，copy一遍-->
13. <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
14. <encoder>
15. <pattern>${CONSOLE_LOG_PATTERN}</pattern>
16. <charset>${CONSOLE_LOG_CHARSET}</charset>
17. </encoder>
18. </appender>
19. <root level="INFO">
20. <appender-ref ref="CONSOLE"/>
21. </root>
22. </configuration>
23.  

然后在spring yaml配置文件配置： 白名单模式

1. logback:
2. stackTrace:
3. skipLine: com.example,java,org # 多个包名以逗号分隔
4. skipLineMode: whitelist #白名单模式
5. maxNumPerCycle: 1 # 每个周期内最大打印全栈的次数，=0时每次均跳过， =1时使用 布隆过滤器
6. cycleDuration: 2h #计数周期
7.  

或者黑名单模式

1. logback:
2. stackTrace:
3. skipLine: com.example,java,org # 多个包名以逗号分隔
4. skipLineMode: blacklist #黑名单模式
5. maxNumPerCycle: 1 # 每个周期内最大打印全栈的次数，=0时每次均跳过， =1时使用 布隆过滤器
6. cycleDuration: 2h #计数周期
7.  

或者 class 或 spring bean (需实现StackLineSkipPredicate)

1. logback:
2. stackTrace:
3. skipLine: com.example.TestStackLineSkipPredicate
4. skipLineMode: predicate_class #谓词类
5. maxNumPerCycle: 1 # 每个周期内最大打印全栈的次数，=0时每次均跳过， =1时使用 布隆过滤器
6. cycleDuration: 2h #计数周期
7.  

或者 janino表达式,使用 line 表示该行的字符串参数, 返回true时表示不打印改行

1. logback:
2. stackTrace:
3. skipLine: "!line.contains(\"com.example\")" #必须以com.example开头才打印
4. skipLineMode: janino_expression #janino表达式
5. maxNumPerCycle: 1 # 每个周期内最大打印全栈的次数，=0时每次均跳过， =1时使用 布隆过滤器
6. cycleDuration: 2h #计数周期
7.  

运行 demo 里的 Test 查看效果:

1. @Slf4j
2. @SpringBootTest
3. class LogNoiseLessDemoApplicationTests {
4.  
5. @Test
6. void contextLoads() {
7. for (int i = 0; i < 5; i++) {
8. log.warn("test", new RuntimeException("test"));
9. }
10. }
11. }
12.  

OK,搞定