一、常用日志Jar关系
2015第30周四Java日志组件
接口:将所有日志实现适配到了一起,用统一的接口调用。
实现:目前主流的日志实现
旧日志到slf4j的适配器:如果使用了slf4j,但是只想用一种实现,想把log4j的日志体系也从logback输出,这个是很有用的。
slf4j到实现的适配器:如果想制定slf4j的具体实现,需要这些包。
slf4J与旧日志框架的关系
slf4j等于commons-logging,是各种日志实现的通用入口,会根据classpath中存在下面哪一个Jar来决定具体的日志实现库。
logback-classic(默认的logback实现)
slf4j-jcl.jar(apache commons logging)
slf4j-logj12.jar(log4j 1.2.4)
slf4j-jdk14(java.util.logging)
将所有使用旧式日志API的第三方类库或旧代码的日志调用转到slfj
jcl-over-slf4j.jar/jcl104-over-slf4j:apache commons logging 1.1.1/1.0.4,直接替换即可。
log4j-over-slf4j.jar:log4j,直接替换即可。
jul-to-slf4j:jdk logging,需要在程序开始时调用SLF4JBridgeHandler.install()来注册listener参考JulOverSlf4jProcessor,可在applicationContext.xml中定义该bean来实现初始化。注意原有的log4j.properites将失效,logback网站上提供转换器,支持从log4j.properties 转换到logback.xml 。
来源: <http://www.cnblogs.com/doit8791/p/4671780.html>
二、实践注意:
1、"臭名昭著"的is*Enabled()条件, 比如下面的写法:
Java代码
- if(log.isDebugEnabled())
- log.debug("Place for your commercial");
历史:避免构造日志耗时,尤其是采用+拼接字符串输出日志时,试用SLF4J使用占位符方式输出日志时,已避免了该情况, 程序员应该专注于日志内容, 而将日志的输出的决定权交给日志框架去非处理。
2、为提高性能尽量避免在日志中输出全类名、方法名、代码行号等信息,试用反射会影响性能。
3、试用日志时我们要考虑是否会出现NPE(空指针异常), 是否会导致OOM? 越界访问? 线程饥饿(log是同步的)? 延迟初始化异常? 日志打爆磁盘等等。
4、正确输出异常堆栈
- try {
- Integer x = null;
- ++x;
- } catch (Exception e) {
- log.error(e); //A
- log.error(e, e); //B
- log.error("" + e); //C
- log.error(e.toString()); //D
- log.error(e.getMessage()); //E
- log.error(null, e); //F
- log.error("", e); //G
- log.error("{}", e); //H
- log.error("{}", e.getMessage()); //I
- log.error("Error reading configuration file: " + e); //J
- log.error("Error reading configuration file: " + e.getMessage()); //K
- log.error("Error reading configuration file", e); //L
- }
上面的代码, 正确输出异常信息的只有G和L, A和B甚至不能在SLF4J中编译通过, 其他的都会丢失异常堆栈信息或者打印了不恰当的信息. 这里只要记住一条, 在日志中输出异常信息, 第一个参数一定是一个字符串, 一般都是对问题的描述信息, 而不能是异常message(因为堆栈里面会有), 第二个参数才是具体的异常实例.
http://macrochen.iteye.com/blog/1399082
三、多线程日志读写注意
多线程环境并发写日志,首先需要保证线程安全,就是说,多个线程一起写日志时,内容不能出现交织。
要做到这一点,最最简单的办法,就是每条线程单独写一个文件,这个方案在淘宝是不现实的,因为应用的线程非常多(仅 HSF 线程池就已经有 600 个线程),如果采用这个方案,会产生很多日志文件。
再简单一点的办法是把写日志作为临界区,进入临界区时用锁来保证每一时刻只有一个线程在写日志,例如 BufferedOutputStream 就是一个写时同步的实现。
应用用 log4j、logback 打日志,如果没特殊配置过,一般就是同步写的。
异步写的方案:任何线程要写日志,只需要把日志事件对象加入日志队列就行了,后台会专门起一个线程从队列取日志、写文件。
这是一个典型的多生产者对单消费者的问题,关键就在于这个队列的实现,因为这里面涉及消费者等待队列不空,生产者等待队列空的逻辑,当时就选择了比较直观的 BlockingQueue。
j.u.c 里比较常见的 BlockingQueue 实现,有 ArrayBlockingQueue、LinkedBlockingQueue、LinkedTransferQueue、SynchronousQueue 这几个:
SynchronousQueue 常用于生产者消费者一对一交换的场景,不适合。
LinkedTransferQueue 是 Java7 里新加的队列实现,在 NIO 框架、线程池框架里常亮相,性能应该不错,不过提交日志到队列,完全不需要等待消费者做 transfer 动作,因此用不上。
LinkedBlockingQueue 是基于链表实现的队列,一头一尾各有一把锁,缺点就是入队有内存分配开销。
ArrayBlockingQueue 是一个定长的环形数组,队列创建之后,就没有内存开销了,但缺点是这个队列共用一把锁,竞争比 LinkedBlockingQueue 激烈。
实测发现用 LinkedBlockingQueue 做队列,吞吐量比 ArrayBlockingQueue 高,但考虑到 ArrayBlockingQueue 本身的定长特性,在写日志 qps 很高时内存波动更稳定,而且队列定长也正好可以作为写日志的“节流阀”(队列满时,新增的日志无法放入,会直接被丢弃,从而起到控制日志写入速度的作用),因此最终选择了 ArrayBlockingQueue。
log4j、logback 等日志框架,有对应的 AsyncAppender 实现异步队列,都选择了 ArrayBlockingQueue。
使用 BlockingQueue 入队有一个细节,就是用 add、put、offer 中的哪一个。add 会抛异常是不合适的,关键还是看 put 还是 offer。put 是一直等,直到入队为止,offer 是不等,或者只尝试等一段时间。相比之下,offer 的实现更合适,对于调用埋点日志,如果队列满,可以直接把日志丢掉不用等;对于更重要一些的业务日志,尽量不丢弃,可以尝试等几百毫秒。如果使用了等的策略,日志队列又经常满的话,会拖慢业务的响应时间,logback 用了 put 来保证重要日志不丢失,在高 qps 时,吞吐量是比用 offer 要差的。
在日志队列这个场景,消费者的速度一般高于生产者速度,因此队列经常处于空状态,消费者每次起来只处理一条或几条日志之后队列又空了只好重新挂起等待,而生产者每放入一条日志,都会唤醒消费者,结果就会导致系统 cs 偏高。
如果把 BlockingQueue 的功能拆开来看,一个功能是在维护队列在并发场景的出队、入队,另一个功能是做生产者、消费者之间的同步策略。
前一个功能可以另外用无锁队列来实现,降低锁争用开销,后一个功能可以针对记日志的场景做专门优化。
j.u.c 里面的 ConcurrentLinkedQueue 就是默认的无锁队列。另外,这篇论文也提出了一个对无锁队列的改进。不过,这些实现都是在无界队列上实施的算法,更适合的数据结构应该是对 ArrayBlockingQueue 的定长环形数组进行改造,把它变为无锁。看到这里,相信有不少同学能想到最近比较火的 Disruptor,这个库的核心就是使用环形数组(RingBuffer)实现无锁队列,性能号称比 ArrayBlockingQueue 要好不少。
多进程写日志的方案有下面几个:
每个进程单独写一个文件。这个方案简单可靠,缺点是对日志收集来说有点不方便,但可以接受。
写文件时,每个进程都先获取文件锁 FileChannel.lock(),写完之后 release。logback 用的是这个策略(prudent=true)。
依赖 write(2) O_APPEND 的原子性:open(2)/write(2) 在设置了 O_APPEND 之后,操作系统可以保证写入是原子操作(一次写出的内容不要超过 PAGE_SIZE=4K),在这里有详细讨论。JVM 里面,如果使用 new FileOutputStream(file, append) 这个 API,第二个参数 append 设置为 true,会带有 O_APPEND 参数。
https://yq.aliyun.com/articles/2920?spm=5176.100239.yqblog1.6.7B3Q9y