浅谈融云即时通讯服务「日志优化」

《神探狄仁杰》剧迷们对狄仁杰的断案能力极为叹服，狄大人总是能将非常诡异的案件查得水落石出，连武则天都赞他“神乎其技”。实际上，狄仁杰之所以被称为“神探”，很大一部分原因，是他擅长通过极为细小的线索推导、还原，进而破案。关注【融云 RongCloud】，了解协同办公平台更多干货。

对应到软件开发上，用来记录系统或程序运行状态的日志，已成为程序运行问题的重要“线索”，它可以记录程序运行过程，快速定位问题，便于程序的监控和优化。

---

日志使用

Java 领域有多种日志框架，Log4j2 是其中一种。Log4j2 凭借可配置化的集成方式、简单的 API、强大的功能及性能优势，成为 Java 领域使用最广泛的日志解决方案。

融云即时通讯服务的日志框架选择的就是 Log4j2。

---

日志级别

Log4j2 定义了 8 个日志级别，分别是：OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE、 ALL。其中常用的日志级别是4个，优先级从低到高为 DEBUG、INFO、WARN、ERROR。

DEBUG
指定细粒度信息事件是最有用的应用程序调试，主要用于开发过程中打印一些运行信息。

INFO
指定能够突出在粗粒度级别的应用程序运行情况的信息，可以帮助程序员有效了解程序的流转，可用于生产环境中输出程序运行的一些重要信息。

WARN
指定具有潜在危害的情况，有些信息是错误信息，但也需要给程序员的一些提示。

ERROR
错误事件，可能仍然允许应用程序继续运行，打印错误和异常信息。

---

日志性能

日志打印对服务器性能产生损耗，会增大服务的延迟，降低服务吞吐量。尤其在高并发大业务量情况下，日志打印得越多，服务的性能损耗越大。

即时通讯服务在进行压力测试过程中，开启 INFO 级别日志与开启 ERROR 级别日志做比较，随着业务量级的增大，服务的性能损耗也不断增大。

而在实际运行中，因私有化部署的约束和对问题排查便利性的考虑，即时通讯服务往往是开启 INFO 级别日志，这就对在 INFO 级别下即时通讯服务的性能提出了更严峻的考验和更高的要求。

为此，融云即时通讯服务除了做好日志级别分类和日志内容精简外，还进行了相关优化。

---

日志优化

关闭 Location 信息

如果 Log4j 配置了%C or $class, %F or %file, %l or %location, %L or %line, %M or %method 等配置项，Log4j 将会获取堆栈的快照，遍历堆栈轨迹来获取 Location 信息，从而影响性能。

对于同步日志记录器来说，速度要慢 1.3 - 5 倍；对于异步日志记录器而言，获取堆栈快照的性能影响甚至更大，因为有位置的日志记录比没有位置的日志记录慢 30-100 倍。因此，异步日志记录器和异步附加器在默认情况下不包含位置信息。

所以，融云即时通讯服务去掉了 %C or $class, %F or %file, %l or %location, %L or %line, %M or %method 等配置，通过在日志中添加类名以及埋点标识的方式用于快速定位问题代码。

使用 Async Loggers

Asynchronous Loggers 是Log4j2中的一个新功能，它们的目标是从对 Logger.log 的调用尽快返回到应用程序。

LMAX Disruptor
Asynchronous Loggers 使用了 Disruptor，Disruotor 是一个无锁的线程间通讯库，不使用队列，获得了更高的吞吐量和更低的延迟，可通过 Maven 引入。

优势
a. 更高的峰值吞吐量
使用异步日志记录器，应用程序可以以 6 – 68 倍于同步日志记录器的速度记录消息。
b. 更低的响应延迟
响应延迟是在一定工作负载下调用 Logger.log 返回所需的时间。

劣势
错误处理。如果在日志记录过程中出现问题并抛出异常，那么 Asynchronous Logger 或 Appender 不太容易向应用程序暴露此问题。不过，可通过混合同步和异步日志记录器的方式处理，即同步和异步日志记录器在配置中组合使用。

全部异步日志记录器

可通过以下方式使所有日志记录器异步。将 disruptor 的 jar 添加到环境变量，并设置服务启动的 JVM 参数，增加

-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

或

-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.BasicAsyncLoggerContextSelector

混合同步和异步日志记录器

同步和异步日志记录器可以在配置中组合使用，这样可提供更大的灵活性，但与所有日志记录器都是异步的相比性能略有下降。

性能比较

吞吐量

下图比较了同步日志记录器、异步 Appender 记录器和异步日志记录器的吞吐量，这是所有线程的总吞吐量。在使用64个线程的测试中，异步日志记录器的速度比异步 Appender 记录器快 12 倍，比同步日志记录器快 68 倍。异步日志记录器的吞吐量随着线程数量的增加而增长，但是不管记录日志的线程数多少，同步日志记录器和异步 Appender 记录器的吞吐量基本不变。

下图将异步日志记录的峰值吞吐量与其他日志框架中的异步 Appender 记录的峰值吞吐量进行了比较，与上图结果类似。异步 Appender 记录器，在添加更多线程时，线程的日志吞吐量基本保持不变,异步日志记录器在多线程场景中能更有效地利用机器上可用的多个核心。

响应延迟

下图比较了 Logback 1.1.7、Log4j 1.2.17 与 Log4j 2.6 各种异步日志记录选项的响应时间延迟，可看到 Logback 1.1.7、Log4j 1.2.17 的延迟峰值比 Log4j 2 大了很多数量级。

下图比较了相同测试的 log4j2 结果，可看到基于ArrayBlockingQueue 的 Async Appender 的响应时间最高， Garbage-free Async Loggers 具有最佳响应时间。

---

测试

测试条件

1. 3000 client 在线
2. 25W 条单聊消息

测试对比

使用的同步日志记录器

使用的全部异步日志记录器

吞吐量对比图

响应延迟对比图

测试结论

优化后，融云即时通讯服务在开启 INFO 级别日志时，使用全部异步日志记录器比使用同步日志记录器在性能上将获得更大提升，吞吐量提升约 50%，响应延迟降低约 50%。

---

回看狄仁杰封神之路不难发现，破案离不开对仅存证据的抽丝剥茧；相应的，想要迅速锁定程序出问题环节，日志就是最有力的“证据”。作为即时通讯服务赛道上长期“参赛者”，融云将秉持初心和使命，坚持自我革命、持续迭代，致力于为更多客户提供最优即时通讯服务。