【问题标题】:Log4j: is it synchronized for multithreaded calls?Log4j:多线程调用是否同步?
【发布时间】:2012-02-18 18:32:08
【问题描述】:

我们在对系统进行压力测试时遇到了一个有趣的问题。我们大量使用 log4j(在 JBOSS 中)进行日志记录。以下是我们常用的一些日志记录的简单示例

void someFunction()
{
Log.info("entered some function");
...

Log.info("existed some function");
}

现在我们注意到有趣的事情是,如果我们针对这个函数启动 100 个线程;每个线程的 Log.info() 调用都是阻塞的。这意味着线程 2 正在等待 thread1 完成“Log.info”调用。在线程 100 的情况下;它最终等待了很长时间。我们正在使用本机文件记录器。

这是一个已知问题吗?

【问题讨论】:

  • Log 是一个类?还是Logger 类型的对象?
  • Log是从Loggerfactory获取的logger类型的对象
  • 好的,谢谢。只是想确定一下。我正在查看Logger 的源代码,发现那里确实有一个synchronized 部分。

标签: java multithreading jboss log4j synchronized


【解决方案1】:

Log4J 必须同步,否则您会在文件中看到交错和乱码的日志消息。但至少在 Logback 中,只有 appenders 是同步的,而不是整个日志消息(因此计算有效日志级别、日志消息等是多线程的)。

但是,即使移除了同步,I/O 也会成为瓶颈,因为它本质上是单线程的。因此考虑减少日志记录的数量,因为是文件访问速度较慢,而不是 Log4J。

您可能还对AsyncAppender 感兴趣,以便在一个不同的线程中对日志消息进行排队。

【讨论】:

  • +1 - 我认为值得一提的是与异步方法的权衡;在进程或系统崩溃的情况下,您不能保证所有日志记录都已写入磁盘
  • 我不确定我是否理解 AsyncAppender。日志记录实际上不是'异步'..意味着发生在一个单独的线程中吗?在我上面的例子中的含义;当我调用 "Log.Info("abc"); 它实际上并没有立即写入文件。它似乎被延迟了?
  • @shegill,是的,它被延迟了。在发送到委托附加程序之前,它会在 AsyncAppender 中缓冲。这就是 Brian 警告在系统崩溃时丢失日志消息的原因;如果您没有在每条日志消息后将附加程序刷新到磁盘,您将面临同样的危险。
  • @Tomasz Nurkiewicz “Log4J 必须同步,否则您会在文件中看到交错和乱码的日志消息”。这正是我在本地多线程应用程序中看到的。无论是否使用 AsyncAppender。
【解决方案2】:

是的,log4j 使用多线程同步。有时并不完美。

我们经历了一些由于 log4j 锁的争用导致性能下降,甚至使用复杂的 toString() 方法导致的死锁。

例如,请参阅 https://issues.apache.org/bugzilla/show_bug.cgi?id=24159https://issues.apache.org/bugzilla/show_bug.cgi?id=41214#c38

我的另一个答案中的更多详细信息: Production settings file for log4j?

我想这是自 JBoss AS 6 以来 logback 存在并切换到自定义 logmanager 的原因之一。

【讨论】:

    【解决方案3】:

    您可能想要的是异步日志记录,请参阅这篇文章了解如何实现:

    Asynchronous logging with log4j

    另外,请考虑使用正确的日志级别。 entered...exi(s)ted... 语句通常应该在 TRACE 级别记录,这在调试时可能会很方便(然后将配置 log4j 设置为在 TRACE 级别记录)。在生产环境中,您可能希望告诉 log4j 仅从级别 INFODEBUG 进行日志记录,从而避免不必要的日志操作。

    另请参阅有关 log4j 性能的问题:

    log4j performance

    【讨论】:

      【解决方案4】:

      其他人已经向你推荐了替代方案,我一直在挖掘源代码,确实有一个 synchronized 部分:

      public void info(Object message) {
          if(repository.isDisabled(Level.INFO_INT))
             return;
          if(Level.INFO.isGreaterOrEqual(this.getEffectiveLevel()))
             forcedLog(FQCN, Level.INFO, message, null);
      }
      
      ...
      
      protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) {
          callAppenders(new LoggingEvent(fqcn, this, level, message, t));
      }
      
      ...
      
      public void callAppenders(LoggingEvent event) {
          int writes = 0;
      
          for(Category c = this; c != null; c=c.parent) {
              // Protected against simultaneous call to addAppender, removeAppender,...
              synchronized(c) {
                  if(c.aai != null) {
                      writes += c.aai.appendLoopOnAppenders(event);
                  }
                  if(!c.additive) {
                      break;
                  }
              }
          }
      
          if(writes == 0) {
              repository.emitNoAppenderWarning(this);
          }
      }
      

      【讨论】:

        【解决方案5】:

        同意之前的回答。任何应用程序中的首要性能改进步骤之一是降低日志级别并使其转储更少的日志。应用程序开发人员应该勤于使用正确的日志记录级别。由于 I/O 和同步,日志记录对性能有巨大影响,尤其是当记录器对象是静态的并且在各个线程之间共享时。

        【讨论】:

          猜你喜欢
          • 1970-01-01
          • 1970-01-01
          • 1970-01-01
          • 1970-01-01
          • 2011-09-16
          • 2010-10-10
          • 1970-01-01
          • 2021-10-25
          相关资源
          最近更新 更多