“AI 技术+人才”如何成为企业增长新引擎?戳此了解>>> 了解详情
写点什么

Java 日志性能那些事

  • 2015-05-26
  • 本文字数:2177 字

    阅读完需:约 7 分钟

在任何系统中,日志都是非常重要的组成部分,它是反映系统运行情况的重要依据,也是排查问题时的必要线索。绝大多数人都认可日志的重要性,但是又有多少人仔细想过该怎么打日志,日志对性能的影响究竟有多大呢?今天就让我们来聊聊 Java 日志性能那些事。

说到 Java 日志,大家肯定都会说要选择合理的日志级别、合理控制日志内容,但是这仅是万里长征第一步……哪怕一些DEBUG级别的日志在生产环境中不会输出到文件中,也可能带来不小的开销。我们撇开判断和方法调用的开销,在 Log4J 2.x 的性能文档中有这样一组对比:

复制代码
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
logger.debug("Entry number: {} is {}", i, entry[i]);

上面两条语句在日志输出上的效果是一样的,但是在关闭DEBUG日志时,它们的开销就不一样了,主要的影响在于字符串转换和字符串拼接上,无论是否生效,前者都会将变量转换为字符串并进行拼接,而后者则只会在需要时执行这些操作。Log4J 官方的测试结论是两者在性能上能相差两个数量级。试想一下,如果某个对象的toString()方法里用了ToStringBuilder来反射输出几十个属性时,这时能省下多少资源。

因此,某些仍在使用 Log4J 1.x 或 Apache Commons Logging(它们不支持{}模板的写法)的公司都会有相应的编码规范,要求在一定级别的日志(比如DEBUGINFO)输出前增加判断:

复制代码
if (logger.isDebugEnabled()) {
logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}

除了日志级别和日志消息,通常在日志中还会包含一些其他信息,比如日期、线程名、类信息、MDC 变量等等,根据 Takipi 的测试,如果在日志中加入class,性能会急剧下降,比起 LogBack 的默认配置,吞吐量的降幅在 6 成左右。如果一定要打印类信息,可以考虑用类名来命名Logger

在分布式系统中,一个请求可能会经过多个不同的子系统,这时最好生成一个 UUID 附在请求中,每个子系统在打印日志时都将该 UUID 放在 MDC 里,便于后续查询相关的日志。《The Ultimate Guide: 5 Methods For Debugging Production Servers At Scale》一文中就如何在生产环境中进行调试给出了不少建议,当中好几条是关于日志的,这就是其中之一。另一条建议是记录下所有未被捕获的日志,其实抛出异常有开销,记录异常同样会带来一定的开销,主要原因是 Throwable类的fillInStackTrace方法默认是同步的:

复制代码
public synchronized native Throwable fillInStackTrace();

一般使用logger.error都会打出异常的堆栈,如果对吞吐量有一定要求,在情况运行时可以考虑覆盖该方法,去掉synchronized native,直接返回实例本身。

聊完日志内容,再来看看Appender。在 Java 中,说起 IO 操作大家都会想起 NIO,到了 JDK 7 还有了 AIO,至少都知道读写加个Buffer,日志也是如此,同步写的Appender在高并发大流量的系统里多少有些力不从心,这时就该使用AsyncAppender了,同样是使用 LogBack:

在 10 线程并发下,输出 200 字符的INFO日志,AsyncAppender的吞吐量最高能是FileAppender的 3.7 倍。在不丢失日志的情况下,同样使用AsyncAppender,队列长度对性能也会有一定影响。

如果使用 Log4J 2.x,那么除了有AsyncAppender,还可以考虑性能更高的异步Logger,由于底层用了 Disruptor ,没有锁的开销,性能更为惊人。根据 Log4J 2.x 的官方测试,同样使用 Log4J 2.x:

64 线程下,异步Logger比异步Appender快 12 倍,比同步Logger68倍。

同样是异步,不同的库之间也会有差异:

同等硬件环境下,Log4J 2.x 全部使用异步Logger会比 LogBack 的AsyncAppender快 12 倍,比 Log4J 1.x 的异步Appender快 19 倍。

(点击放大图像)

Log4J 2.x 的异步Logger性能强悍,但也有不同的声音,觉得这只是个看上去很优雅,只能当成一个玩具。关于这个问题,还是留给读者自己来思考吧。

如果一定要用同步的 Appender,那么可以考虑使用ConsoleAppender,然后将STDOUT重定向到文件里,这样大约也能有 10% 左右的性能提升。

大部分生产系统都是集群部署,对于分布在不同服务器上的日志,用 Logstash 之类的工具收集就好了。很多时候还会在单机上部署多实例以便充分利用服务器资源,这时千万不要贪图日志监控或者日志查询方便,将多个实例的日志写到同一个日志文件中,虽然 LogBack 提供了prudent模式,能够让多个 JVM 往同一个文件里写日志,但此种方式对性能同样也有影响,大约会使性能降低 10%。

如果对同一个日志文件有大量的写需求,可以考虑拆分日志到不同的文件,做法之一是添加多个Appender,同时修改代码,不同的情况使用不同Logger;LogBack 提供了SiftingAppender,可以直接根据 MDC 的内容拆分日志, Jetty 的教程中就有根据host来拆分日志的范例,而根据 Takipi 的测试,SiftingAppender的性能会随着拆分文件数的增长一同提升,当拆分为 4 个文件时,10 并发下SiftingAppender的吞吐量约是FileAppender的 3 倍多。

看了上面这么多的数据,不知您是否觉得自己的日志有不少改进的余地,您还没有把系统优化到极致,亦或者您还有其他日志优化的方法,不妨分享给大家。


感谢丁晓昀对本文的审校。

给InfoQ 中文站投稿或者参与内容翻译工作,请邮件至 editors@cn.infoq.com 。也欢迎大家通过新浪微博( @InfoQ @丁晓昀),微信(微信号: InfoQChina )关注我们,并与我们的编辑和其他读者朋友交流(欢迎加入 InfoQ 读者交流群)。

2015-05-26 21:1819710
用户头像

发布了 135 篇内容, 共 58.4 次阅读, 收获喜欢 43 次。

关注

评论

发布
暂无评论
发现更多内容

Week02总结

leis

架构师训练营week2 命题作业

a晖

第2周 学习总结

sunpengjian

第二周作业

孙强

架构师课程第二周总结

dongge

Homework-依赖倒置原则的理解

River Tree

Homework 依赖倒置原则

week2-依赖倒置原则&接口隔离原则

暖丶冬

Wireshark的使用与数据分析(三)--显示过滤器

姬翔

Wireshark

第二周作业

田振宇

<<架构师训练营>> 第二周学习总结

R20114

第二课作业

lwyanhao

Week001总结作业

徐培

架构师训练营-Week 02 命题作业

华乐彬

极客大学架构师训练营 设计原则

架构师训练营 No.2 周总结

连增申

设计模式与设计原则(第二周总结)

麻辣

极客大学第二周作业

方堃

极客大学

第三课 容我三思

Geek_bobo

课堂作业week2

Dennis

第二周作业 - 命题作业

molly

极客大学架构师训练营

极客时间第 0 期架构师训练营第二周作业

2流程序员

架构师训练营第二周总结

好名字

极客大学架构师训练营 作业

架构师训练营丨第二周丨学习总结

Frode

极客大学架构师训练营

架构师训练营总结 -2

River Tree

架构 总结 软件设计原则

【第二周】命题作业——软件设计原则

三尾鱼

面向对象 极客大学架构师训练营

接口隔离原则优化 Cache 类设计

leis

第2周 架构师实现自己架构目标的主要手段

陆不得

架构师训练营第二周总结

草原上的奔跑

架构师训练营第 02周—— 练习

李伟

极客大学架构师训练营

第二课学习总结

lwyanhao

第二周总结

孙强

解决 Jenkins 中使用代理来执行 npm install 的问题

jerry.mei

Docker DevOps 运维 jenkins

Java日志性能那些事_Java_丁雪丰_InfoQ精选文章