我的 log4j 过滤器出了什么问题？ （这会让tomcat挂掉！）

Question

我们最近使用自定义过滤器向 log4j 配置添加了一个过滤器。 目标是停止一次又一次重复相同的日志，而是将其替换为：

日志+“最后一行重复x次”

我们编写了以下过滤器，效果很好。但随后，我们开始注意到tomcat5.5的奇怪死锁和挂起。

当我们删除此过滤器时，错误就会停止发生。 （是的，我们对此非常确定）。

除了这个经验观察之外，JVM 的堆堆栈有许多 log4j 线程被阻塞并等待 tomcat 监视器被释放。

这是我们的过滤器的代码。非常基本。有什么问题吗？

public class RepeatFilter extends Filter {
String lastMessage;
Category lastLogger;
int repeatCount = 0;

@Override
public int decide(LoggingEvent event) {
    // get the rendered (String) form of the message
    String msg = event.getRenderedMessage();

    if(msg == null || msg.startWith("Last message repeated "){
        return Filter.NEUTRAL;
    }

    if(msg.equals(lastMessage)) {
        repeatCount++;
        return Filter.DENY;
    } else {
        if(repeatCount>0){
            String msgToLog = "Last message repeated " + repeatCount + " time(s).";
            repeatCount = 0;
            lastLogger.log(event.getLevel(), msgToLog);
        }
    }

    lastLogger = event.getLogger();
    lastMessage = msg;
    return Filter.NEUTRAL;
}

}

编辑 ： 是的，当我们在过滤器内使用记录器时，这是一个递归。事实上，服务器在lastLogger.log(...)行之后挂起。 但我们确实需要编写一条自定义消息（重复 x 次）。我们尝试不在过滤器内使用记录器，但我们还没有找到方法。

编辑2： 我使用的是log4j 1.2.15版本。

编辑3： 我们将尝试的事情：

• 使我们所有的appender都嵌套在AsyncAppender中

Edit 4 ： 将每个追加器包装在 asyncAppender 中并不能解决问题

Answer 1

可能的死锁

查看源代码，我发现当记录事件时，会在 Category 上获得一个锁，然后在每个 AppenderSkeleton 上获得一个锁。事件已调度。如果两个 Category 实例使用相同的附加程序（这很常见），则尝试从附加到该附加程序的 Appender（或附加的 Filter）进行日志记录appender）肯定会导致死锁。

例如，有两个 Category 对象，C1 和 C2，以及一个 Appender，A< /代码>。 Thread T1 获取 C1 上的锁，然后获取 A 上的锁，然后开始处理 FilterA 上的 code> 链。

同时，Thread T2 获取C2 上的锁。它无法获取 A 上的锁，因为它由 T1 持有，因此它会等待。

现在假设（由过滤器）指示 T1 将消息记录到 C2。它无法获取 C2 上的锁，因为它由 T2 持有。僵局。

如果您从线程转储中发布了更多信息，应该可以判断这是否是真正的死锁，如果是，则可以判断哪些对象存在争用。

可能的解决方案

如果确实发生了这种情况，则似乎可以通过仅将“重复”消息记录到“当前”记录器（即由过滤器评估的事件的记录器）来避免该问题。实现此目的的一种方法是跟踪每个记录器的重复次数。

public class RepeatFilter
  extends Filter
{

  private final Map<Category, Repeat> repeats = 
    new HashMap<Category, Repeat>();

  @Override
  public int decide(LoggingEvent event)
  {
    String message = event.getRenderedMessage();
    if ((message == null) || message.startsWith("Last message repeated "))
      return Filter.NEUTRAL;
    Category logger = event.getLogger();
    Repeat r = repeats.get(logger);
    if (r == null)
      repeats.put(logger, r = new Repeat());
    if (message.equals(r.message)) {
      ++r.count;
      return Filter.DENY;
    }
    if (r.count > 0) {
      logger.log(r.level, "Last message repeated " + r.count + " time(s).");
      r.count = 0;
    }
    r.message = message;
    r.level = event.getLevel();
    return Filter.NEUTRAL;
  }

  private final class Repeat
  {

    Priority level;

    String message;

    int count;

  }

}

这可能不是您想要的，因为其他记录器上的事件不会“刷新”类别的“重复”消息。另一方面，它可能会更有效地压缩日志，因为相同的消息可能会在同一个记录器上重复。