基于Logback TurboFilter的日志异常限流过滤器失效问题排查

我仔细看了你的ExceptionFilter实现，发现几个可能导致未达预期效果的问题，同时也有一些可以优化的点，下面逐一说明：

1. 并发场景下的竞态条件问题 #

你的实现中，containsKey、get和put操作不是原子性的，在多线程同时处理同一个异常时，会出现重复输出的情况。比如：

• 线程A检测到缓存中没有该异常类名，准备存入当前时间
• 同时线程B也检测到缓存中没有该异常类名，也准备存入当前时间
• 最终两个线程都会返回FilterReply.NEUTRAL，导致同一异常被输出两次，不符合"指定时长内只输出一次"的预期

2. 缺少缓存过期清理机制 #

ConcurrentHashMap中的条目会永久保存，即使某个异常类再也不会出现，对应的缓存条目也不会被删除。这会导致内存占用越来越高，长期运行可能引发内存泄漏问题。

3. 未考虑嵌套异常的场景 #

当前实现只捕获了最外层的异常类名，但实际业务中很多异常会包含cause嵌套。如果同一个根异常被包装成不同的外层异常抛出，你的过滤器会认为是不同的异常，无法正确限流。

修复后的实现 #

针对以上问题，我调整了代码，解决了并发问题，新增了缓存清理，并支持嵌套异常的处理：

package com.example;

import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import org.slf4j.Marker;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.turbo.TurboFilter;
import ch.qos.logback.core.spi.FilterReply;

public class ExceptionFilter extends TurboFilter {
    private final ConcurrentHashMap<String, Long> exceptionCache = new ConcurrentHashMap<>();
    private long suppressTimeInMS = 10 * 60 * 1000;
    private final ScheduledExecutorService scheduler = Executors.newSingleThreadScheduledExecutor();

    @Override
    public void start() {
        super.start();
        // 每小时清理一次过期的缓存条目
        scheduler.scheduleAtFixedRate(this::cleanExpiredCache, 1, 1, TimeUnit.HOURS);
    }

    @Override
    public void stop() {
        scheduler.shutdown();
        super.stop();
    }

    @Override
    public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
        if (t == null) {
            return FilterReply.NEUTRAL;
        }
        // 获取根异常的类名
        String exceptionName = getRootException(t).getClass().getName();
        long currTime = System.currentTimeMillis();

        // 使用compute方法保证原子操作
        return exceptionCache.compute(exceptionName, (key, lastTime) -> {
            if (lastTime == null || (currTime - lastTime) >= suppressTimeInMS) {
                // 允许输出，更新缓存时间
                return currTime;
            } else {
                // 拒绝输出，保留原时间戳
                return lastTime;
            }
        }) == currTime ? FilterReply.NEUTRAL : FilterReply.DENY;
    }

    private Throwable getRootException(Throwable t) {
        while (t.getCause() != null && t.getCause() != t) {
            t = t.getCause();
        }
        return t;
    }

    public void setSuppressTimeInMS(long suppressTimeInMS) {
        this.suppressTimeInMS = suppressTimeInMS;
    }

    private void cleanExpiredCache() {
        long currTime = System.currentTimeMillis();
        exceptionCache.entrySet().removeIf(entry -> (currTime - entry.getValue()) > suppressTimeInMS);
    }
}

关键优化点说明 #

• 原子性操作：使用ConcurrentHashMap.compute方法替代分开的get和put，保证整个判断和更新操作是原子的，避免多线程竞态条件。
• 缓存过期清理：启动一个定时任务，定期清理超过suppressTimeInMS的缓存条目，防止内存泄漏。
• 根异常处理：新增getRootException方法，获取异常链中的根异常，确保同一根异常无论被包装多少次，都会被正确限流。
• 完善生命周期管理：重写stop方法，关闭定时任务，避免资源泄漏。

额外注意事项 #

确保在你的Logback配置文件（如logback.xml）中正确配置这个过滤器，并且放在其他过滤器之前：

<configuration>
    <turboFilter class="com.example.ExceptionFilter">
        <suppressTimeInMS>600000</suppressTimeInMS> <!-- 10分钟 -->
    </turboFilter>
    
    <!-- 其他配置 -->
</configuration>

内容的提问来源于stack exchange，提问作者CuriousMind