日志优化

标签: 日志 优化 | 发表时间:2015-05-27 19:28 | 作者:xxh02
出处:http://www.iteye.com

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

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


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

 

文章出处:http://www.infoq.com/cn/articles/things-of-java-log-performance



已有 0 人发表留言,猛击->> 这里<<-参与讨论


ITeye推荐



相关 [日志 优化] 推荐:

日志优化

- - 互联网 - ITeye博客
在任何系统中,日志都是非常重要的组成部分,它是反映系统运行情况的重要依据,也是排查问题时的必要线索. 绝大多数人都认可日志的重要性,但是又有多少人仔细想过该怎么打日志,日志对性能的影响究竟有多大呢. 今天就让我们来聊聊Java日志性能那些事. 说到Java日志,大家肯定都会说要选择合理的日志级别、合理控制日志内容,但是这仅是万里长征第一步……哪怕一些 DEBUG级别的日志在生产环境中不会输出到文件中,也可能带来不小的开销.

log4j日志性能优化

- - 编程语言 - ITeye博客
       在软件系统中,打日志几乎是每个系统都会使用的行为. 不管是用来记录系统健康状态,辅助问题定位,还是收集数据,以便后续数据分析等,日志都起着举足轻重的作用. 但是IO的阻塞行为和磁盘的读写速度低下意味着写日志并非是没有代价的.           在很多系统中,日志模块用的都是log4j,打日志用的都是同步方法,基本配置如下:.

访问日志IO性能优化

- - CSDN博客推荐文章
在高并发量的场景下磁盘IO往往是性能的瓶颈所在,访问日志涉及到频繁的写操作,所以这部分要尽可能地优化,不然将拖累系统的整体性能. 针对文件记录及数据库记录两种方式可以有以下措施提高写性能,. 将日志写入文件的一般操作步骤是打开-写入-关闭,但假如在需要频繁写入日志的场景下,这种方式在性能上肯定会存在问题,因为每次打开关闭都是需要成本开销的,所以必须要想想是否有别的更好的方式,竟然问题出现在打开关闭的次数,那么解决问题思路就从这里下手,可以在第一次打开写入日志后不进行关闭操作,保持打开的状态,下一次写入则无需再次打开可直接写入.

MYSQL优化之关闭文件系统日志

- - Linux - 操作系统 - ITeye博客
通常数据库系统在数据大量操作时,会产生很大的磁盘io,关闭linux各文件系统的日志功能可以提高数据库吞吐量. 1)查看文件系统是否开启日志功能了. tune2fs -l /dev/sda2 | grep 'has_journal' 如果返回结果中出现has_journal,则说明该文件系统开启了日志(jbd,也即 journaling block device).

日志管理

- - CSDN博客系统运维推荐文章
#很关键 [[email protected] ~]# ls /var/log/ anaconda.ifcfg.log. tallylog #关键日志,大部分记录在里面 [[email protected] ~]# ls /var/log/messages /var/log/messages. [[email protected] ~]# ps -ef|grep log #系统日志服务 root.

nginx日志切割

- - haohtml's blog
nginx的日志文件没有rotate功能. 如果你不处理,日志文件将变得越来越大,还好我们可以写一个nginx日志切割脚本来自动切割日志文件. 第一步就是重命名日志文件,不用担心重命名后nginx找不到日志文件而丢失日志. 在你未重新打开原名字的日志文件前,nginx还是会向你重命名的文件写日志,linux是靠文件描述符而不是文件名定位文件.

flume日志采集

- - CSDN博客推荐文章
1.1.2.  Client端Log4j配置文件. (黄色文字为需要配置的内容). //日志Appender修改为flume提供的Log4jAppender. //日志需要发送到的端口号,该端口要有ARVO类型的source在监听. //日志需要发送到的主机ip,该主机运行着ARVO类型的source.

Flume日志收集

- - 企业架构 - ITeye博客
转: http://www.cnblogs.com/oubo/archive/2012/05/25/2517751.html. Flume是一个分布式、可靠、和高可用的海量日志聚合的系统,支持在系统中定制各类数据发送方,用于收集数据;同时,Flume提供对数据进行简单处理,并写到各种数据接受方(可定制)的能力.

GC 日志分析

- - 码蜂笔记
不同的JVM及其选项会输出不同的日志. 生成下面日志使用的选项: -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:d:/GClogs/tomcat6-gc.log. 最前面的数字 4.231 和 4.445 代表虚拟机启动以来的秒数.

Nginx 日志滚动

- - Linux - 操作系统 - ITeye博客
Nginx 日志滚动配置. 在linux下配置日志滚动一般都用系统自带的logrotate,但是在之前的使用中发现,如果一个daemon只打开一个日志文件写日志,在logroate的配置文件中使用copytruncate,会有少部分日志丢失. 在对日志要求不是特别严格的情况下这是可行的,但有时候这丢失的几行日志很重要,就需要一个比较严格的日志滚动方法.