Log4j 2：性能接近疯狂

最近，Apache社区中一位受人尊敬的成员尝试了Log4j 2并在Twitter上写道：

@TheASF ＃log4j2摇摇欲坠！性能接近疯狂^^ http://t.co/04K6F4Xkaa

— Mark Struberg（@struberg） 2013年5月7日

（来自Mark Struberg的名言：@TheASF＃log4j2摇摇欲坠！性能接近疯狂^^ http://logging.apache.org/log4j/2.x/）

在Remko Popma贡献了一些东西（现在称为“ AsyncLoggers”）之后不久便发生了。某些人可能知道Log4j 2已经具有AsyncAppenders。它们相似，就像您在Log4j 1和其他日志记录框架中可以找到的一样。

老实说：我对新功能并不感到兴奋，直到我阅读了有关其性能的推文并对此感到好奇。显然，Java日志记录有许多目标。其中： 日志记录必须和地狱一样快 。没有人希望他的日志记录框架成为瓶颈。当然，登录时总会有成本。 CPU必须执行一些操作。即使您决定不编写日志语句，也正在发生某些事情。预计日志是不可见的。

到目前为止，众所周知的日志记录框架在速度上是相似的。基准毕竟是不可靠的。我们已经在Apache Logging上建立了一些基准。有时，一个日志记录框架会获胜，有时则是另一个。但总而言之，您可以说他们都很好
您可以选择自己喜欢的任何方式。直到获得Remko的贡献，Log4j 2变得“异常快速”。

运行一个线程的小型软件项目可能不太在乎性能。在运行SaaS时，您根本不知道您的应用何时会吸引到您需要扩展的吸引力。然后，您突然需要一些额外的电源。

使用Log4j 2，运行64个线程可能为您带来的日志吞吐量是同类框架的十二倍。

我们说每秒超过18,000,000条消息，而其他消息在同一环境中的发送量大约为1,500,000条或更少 。

我看到了图表，但简直不敢相信。一定有问题。我重新检查了。我自己进行了测试。就像这样： Log4j 2的速度非常快。

异步性能，最后阅读时间：2013年7月19日

截至目前，我们拥有一个日志记录框架，该框架的性能比那里的其他所有日志记录框架都要好。 到目前为止，如果速度很重要，那么当我们不想使用Log4j 2时，我们需要证明我们的决定是正确的。 Log4j 2之外的所有其他内容都可能成为瓶颈和风险。有了如此快速的日志记录框架，您甚至可以考虑比以前更多地记录生产中的日志。

最终，我给雷姆科写了一封电子邮件，问他旧的AsyncAppenders和新的异步记录器之间到底有什么区别 。

旧的AsynAppenders和新的AsyncLoggers之间的区别

他告诉我：“异步记录器在做两件事上与AsyncAppender有所不同，”他们试图在将日志消息传递到另一个线程之前做最少的工作，并且他们使用不同的机制在生产者和生产者之间传递信息。消费者线程。 AsyncAppender使用ArrayBlockingQueue将消息传递给写入磁盘的线程， 异步记录器使用LMAX Disruptor库 。特别是Disruptor的性能差异很大。”

换句话说，AsyncAppender使用先进先出队列来处理消息。但是异步记录器使用了新的东西-Disruptor。老实说，我从未听说过。而且，我从未想过要扩展我的日志记录框架。当有人说“扩展系统”时，我想到了数据库，应用服务器等等，但通常不会记录日志。在生产中，记录已关闭。故事结局。

但是，雷姆科（Remko）考虑进行日志记录时进行扩展。

“查看异步记录器的性能测试结果，您会注意到的第一件事是，某些记录方式的伸缩性要好于其他方式。通过更好地扩展，我的意思是当添加更多线程时，您将获得更多的吞吐量。如果您添加的每个线程的吞吐量都增加了一个恒定值，那么您将具有线性可伸缩性。这是非常可取的，但可能很难实现。”他写道。

“将同步与异步进行比较，您将期望任何异步机制的扩展都比同步日志记录好得多，因为您不再在生产线程中执行I / O，而且我们都知道'I / O很慢'（而且我会再说一遍）”。

是的，完全是我的理解。我认为将某些内容发送到队列就足够了，而其他的则可以将其接收并编写消息。该应用程序将继续运行。雷姆科写道，这正是旧的AsyncAppender所做的：

“使用AsyncAppender，您的所有应用程序线程所需要做的就是创建一个LogEvent对象，并将其放在ArrayBlockingQueue上；然后，使用线程将这些事件从队列中移出并完成所有耗时的工作。即，将事件转换为字节并将这些字节写入I / O设备的工作。由于应用程序线程不需要执行I / O，因此您希望它可以更好地扩展，这意味着添加线程将允许您记录更多事件。

如果您相信像我一样，请坐下并深呼吸。我们错了。

他写道：“事实可能并非如此。”

“如果查看所有日志记录框架的AsyncAppenders的性能数字，就会发现，每增加一倍的线程数，每个线程的吞吐量就会减少一半。”

“因此，您的总吞吐量或多或少保持不变！他告诉我，AsyncAppenders比同步日志记录要快，但是它们在某种意义上是相似的，即当您添加更多线程时，它们都不为您提供更多的总吞吐量。

它像锤子一样打在我身上。基本上，而不是通过添加更多线程来提高日志记录速度，基本上是：没有。毕竟，直到现在Appender都没有扩展。我问雷姆科为什么会这样。

事实证明，队列并不是在线程之间传递信息的最佳数据结构。作为标准Java库的一部分的并发队列使用锁来确保值不会被破坏并确保线程之间的数据可见性。

LMAX破坏者？

“ LMAX团队对此进行了大量研究，发现这些队列有很多锁争用。他们发现一个有趣的事情是队列始终是满的或空的：如果生产者速度更快，则在大多数情况下您的队列将是满的（这本身可能就是一个问题）。如果您的使用者速度足够快，则您的队列在大多数情况下将是空的。无论哪种方式，您都将在队列的开头或结尾都有争用，生产者线程和使用者线程都想在其中更新同一字段。为了解决这个问题，LMAX团队提出了Disruptor库，该库是用于在线程之间传递消息的无锁数据结构。这是Disruptor和ArrayBlockingQueue之间的性能比较：性能比较。”

哇。经过这些年的Java编程，我实际上再次感觉像是初级程序员。我错过了LMAX破坏者，甚至从未考虑使用Queue带来的性能问题。我想知道到目前为止还没有发现什么其他性能问题。我意识到，我不得不重新学习Java。

我问雷姆科，他怎么能找到像LMAX破坏者这样的图书馆。我的意思是，没有人编写软件，创建队列类的实例，怀疑其性能并最终在互联网上搜索“更好的东西”。

还是真的有这种人？

“我如何发现Disruptor？简短的答案是，这全都是错误。”他开始说道。

“好吧，也许这有点太短了，所以答案更长一些：我的一位同事写了一个小的记录器，本质上在队列中添加了带时间戳的日志消息，并带有后台线程，这些线程使这些字符串脱离了队列。并将它们写入磁盘。他之所以这样做，是因为他需要比log4j-1.x更好的性能。我做了一些测试，发现它更快，我不记得确切多少。我很惊讶，因为我已经使用log4j多年了，并且从未想到过它会轻易胜过。在那之前，我一直以为著名的库会很快，因为……说实话，我只是以为。因此，这让我大开眼界。但是，自定义记录器在功能上有些勉强，所以我开始四处寻找替代方案。”

“在我开始谈论Disruptor之前，我必须坦白一些东西。最近，我回过头来查看自定义记录器比log4j-1.x快多少，但是当我测量时，它实际上要慢一些！原来，我一直在将自定义记录器与log4j-2.0的旧beta（我认为beta3或beta4）进行比较。这些Beta版中的AsyncAppender仍然存在性能问题（如果您好奇，则为LOG4J2-153）。如果我将自定义记录器与log4j-1.x中的AsyncAppender进行了比较，我会发现log4j-1.x更快，并且我不会再考虑了。但是由于犯了这个错误，我开始寻找功能更丰富的其他高性能日志记录库。我没有找到这样的日志库，但是遇到了很多其他有趣的东西，包括Disruptor。最终，我决定尝试将具有良好代码基础的Log4j-2与Disruptor结合使用。结果最终被Log4j-2本身接受，其余的，正如他们所说的，已成为历史。”

“我在这里提到的一件事是彼得·劳瑞（Peter Lawrey）的编年史图书馆。 Chronicle使用内存映射文件以极低的延迟每秒将数千万条消息写入磁盘。还记得上面我说过的“我们都知道I / O速度很慢”吗？ 纪事表明，同步I / O可以非常非常快。 ”。

“通过彼得的工作，我遇到了破坏者。关于Disruptor的资料很多。只是给您一些提示：

马丁·福勒（Martin Fowler）：LMAX
特里莎（Trisha Lee）在引擎盖下的LMAX上使用（现在略过时，但我知道的最详细的资料）
…像这样的视频演示

强烈建议使用Disruptor Google组。

推荐的有关Java性能的阅读材料通常是：

马丁·汤普森（Martin Thompson）的“机械同情”
马丁·汤普森演讲。

Martin Thompson就Java高性能计算的各个方面做了很多文章和演示。他出色地完成了引擎盖下正在进行的复杂操作。”

阅读此电子邮件后，我的书签文件夹已满，并且我非常感谢您有很多起点来提高我对Java性能的了解。

我应该默认使用AsyncLoggers吗？

我确定我想使用新的异步记录器。这听起来真是太棒了。但另一方面，我有点害怕，甚至有点偏执，无法包括新的依赖项或新技术，例如新的Log4j 2 Async Loggers。我问雷姆科，他是否默认使用新功能，还是仅在少数有限的用例中启用它们。

“ 我默认使用异步记录器 ，是的。”他写道。 “一个用例的时候，你会_not_要使用异步日志记录是当您使用日志记录审计目的。在这种情况下，记录错误是您的应用程序需要了解和处理的问题。我相信大多数应用程序都是不同的，因为它们不太在乎记录错误。大多数应用程序都不想在发生日志记录异常时停止，实际上，他们甚至都不希望知道它。默认情况下，Log4j-2.0中的追加器将抑制异常，因此应用程序无需尝试/捕获每个日志语句。如果这是您的用法，那么使用异步记录器将不会造成任何损失，因此您只能获得收益，即性能得到改善。”

“我应该提到的一个不错的小细节是，异步记录器和异步附加器都修复了一些在Log4j-1.x中一直困扰我的东西，即它们将在记录队列中的最后一个事件后刷新缓冲区 。对于Log4j-1.x，如果使用缓冲的I / O，则通常看不到最后几个日志事件，因为它们仍卡在内存缓冲区中。唯一的选择是将InstantFlush设置为true，这将在每个单个日志事件上强制使用磁盘I / O，并会影响性能。使用Log4j-2.0中的Async Loggers和Appenders，您的日志语句都被刷新到磁盘上，因此它们始终可见，但这是以非常有效的方式发生的。”

登录使用Log4js AsyncLoggers冒险吗？

但是考虑到Log4j-1存在严重的线程问题，并且现代世界一直在使用云计算和集群来扩展其应用程序， 异步日志记录不是某种额外的风险吗？ 还是安全？ 我知道我的问题听起来像是决策者而不是开发人员的问题。但是整个LMAX对我来说还是那么新，并且由于我保留了旧的而且非常丑陋的Log4j 1代码，所以我只需要问一下。

雷姆科：“那里有很多问题。首先，从并发角度看，Log4j-2是否比Log4j-1.x安全？我相信是这样。 Log4j-2团队付出了巨大的努力来支持多线程应用程序，并且异步记录器只是该项目的一个非常新的且相对较小的功能。与Log4j-1.x相比，Log4j-2使用的粒度锁定更多，并且在结构上更简单，这将导致更少的问题，并且出现的任何问题都将更易于解决。”

“另一方面，Log4j-2仍处于测试阶段，并且仍在积极开发中，尽管最近我认为大多数精力都花在了修复问题和捆绑松散的末端上，而不是添加新功能。 我相信它足够稳定以供生产使用。 如果出于性能或其他原因考虑使用Log4j-2，我建议您进行尽职调查和测试，就像在项目中采用任何其他第三方库之前一样。”

（旁注：可以很快找到Log4j2的稳定版本，很可能是2013年秋天）。

对我来说听起来不错。是的，尽管我个人没有在Log4j 2存储库中编写代码，但从我对项目的观察中我可以完全同意这一点。

“我看到的另一个问题是： 异步日志记录比同步日志记录有风险吗？我不这么认为，实际上，如果您的应用程序是多线程的，则情况可能恰恰相反：一旦将日志事件移交给执行I / O的使用者线程，则只有一个线程在处理布局，附加程序以及所有其他与日志记录相关的组件。因此，在移交之后，您将成为单线程的，并且您无需再担心任何线程问题，例如死锁和活动性等。”

“您可以更进一步，使您的业务逻辑完全单线程化，并使用干扰器进行所有I / O或与外部系统的通信。没有锁争用的单线程业务逻辑可以非常快。 LMAX的结果（600万笔事务/秒，延迟少于10毫秒）是不言而喻的。”

阅读雷姆科的信息，我学到了三件事。