概述
在刚接触日志框架时,被很多日志框架搞的头晕,下面将整体介绍下当前流行的开源日志框架,并重点介绍log4j的日志输出原理及配置指导
日志框架 | 简介 | 参考 |
JUL | JDK自带日志框架(java.util.logging),由于效率及灵活性较差,目前使用的较少 | http://docs.oracle.com/javase/1.5.0/docs/guide/logging/overview.html#1.0 |
JCL | Apache Common-Logging是apache开源的日志接口系统,在java系统中,有多种的日志实现方式,该框架仅提供日志输出接口,在实际运行时,根据应用需要,灵活切换日志实现; 在slf4j日志接口出现之前,采用JCL+log4j实现日志项目较多;但该框架有个致命的问题:在OSGI这样的框架无法正常工作 | http://commons.apache.org/proper/commons-logging/index.html |
Slf4j | 也是一种日志接口系统,类似JCL,但相比JCL,其可以在OSGi这样的框架上完美运行,该框架作者,实现了log4j/logback | http://www.slf4j.org/ |
Log4j | 使用最为广泛的一个日志框架系统,通过控制配置文件,我们可以方便的按特定的格式,将日志输出至控制台、文件、远程日志服务器,支持文件的自动切换备份 | http://logging.apache.org/log4j/1.2/ |
Logback | 该框架与log4j框架作者是同一个人,由于其调整了实现框架,输出日志性能高于Log4j,且其支持自动备份压缩,该框架作者极力推荐使用Logback替换Log4j | http://logback.qos.ch/ |
由上表总结我们可以看到,如后续有新项目,建议采用slf4j+logback实现,但由于多方面原因,目前log4j使用依然较普遍,下面将重点介绍log4j
log4j日志输出原理
log4j(log for java)主要是通过三个类来完成日志的输出:Loggers, Appenders and Layouts
Loggers:用于输出日志的实例
- 1】Logger之间存在父子关系,默认子Logger对应的日志输出请求会同时打印至所有的父Logger中
例如有两个类:com.ucweb.account.sdk.TestA,com.ucweb.account.TestB,且配置文件中配置了对应的log4j.logger.com.ucweb.account.sdk/log4j.logger.com.ucweb.account 类TestA对应通过org.apache.log4j.Logger.getLogger(Class clazz)获取对应的LoggerA; TestB对应通过org.apache.log4j.Logger.getLogger(Class clazz)获取对应的LoggerB, 则LoggerA的父Logger就是LoggerB, 而LoggerA和LoggerB的根Logger就是RootLogger
- 2】可以通过自定义logger名称,然后通过getLogger(String name)获取对应实例
- 3】唯一的RootLogger,每个应用都应该配置一个RootLooger,它是所有其它Logger的根,如未配置对应的Logger,则其日志默认全部打印至RootLogger
Appenders:用户定义最终日志输出的目标:控制台、文件、远程服务器
最常用:org.apache.log4j.ConsoleAppender/org.apache.log4j.RollingFileAppender
Layouts:定义日志输出格式:时间戳、线程名称、日志级别、日志内容、对应输出该日志的类、对应输出该日志的方法、行号及MDC信息
最常用:org.apache.log4j.PatternLayout
三者之间的关系:
每个logger可以配置多个Appender,每个Appender对应一个Layout,在输出日志时,会依次将日志内容按照Layout的格式输出对应的Appender上
目前jws框架中的使用情况
- jws是从playframework框架演变而来,playframework 1.x版本是使用:slf4j+log4j; 2.x版本切换至slf4j+logback
- jws对外提供的日志接口jws.Logger,其主要提供两类输出接口方式:
debug/info/warn/error/fatal:这类接口日志默认统一输出到jws.log日志文件 event:这类接口日志默认输出至由event指定的logger名称上,例如event("error","msg info"),将输出值error.log中;
【缺点】:
1)使用非event方式输出日志,所有日志都输出到jws.log,在多个线程同时输出日志时,存在资源竞争; 2)使用event方式虽然可以解决问题1),但该方式无法输出对应日志输出类及方法信息; 3)目前jws框架,默认提供的日志输出Layout是不打印“线程名+类信息+方法信息+日志出错行信息”,非常不利于定位问题;
log4j配置
配置方式: log4j可以通过properties/xml两种方式配置(仅文件格式不同),建议用properties文件编写对应配置项,下面给出一个日志配置示例:
#对一个应用来说,必须要有一个rootLooger #所有的Logger配置对应的value值都是类似:级别,Appender-1[,Appender-2,...,Appender-n]; #其中级别取值:all,debug,info,warn,error,fatal,off,建议使用:info,warn,error这三个级别 #其中Appender-x,必须是一个存在与当前配置文件的Appender log4j.rootLogger=warn,rootAppender #对应的Appender类别 log4j.appender.rootAppender=org.apache.log4j.RollingFileAppender #如下的属性像是与具体的Appender类别相关 #日志文件路径,相对与当前程序运行目录 log4j.appender.rootAppender.File=logs/root.log #单个日志文件大小-最大值,下面配置表示:root.log文件大小超过20M后就会自动备份root.log.1,然后重写新文件 log4j.appender.rootAppender.MaxFileSize=20MB #备份文件最大个如,下面配置表示:备份文件达到100个后,自动清除最老的文件 log4j.appender.rootAppender.MaxBackupIndex=100 #Layout类别 log4j.appender.rootAppender.layout=org.apache.log4j.PatternLayout #下面的配置属性,与具体的Layout类别相关 #%d{yyyy-MM-dd HH:mm:ssS} 按对应格式输出时间信息; #%p 日志级别 #[%t] 对应线程名称 #%m 对应日志内容 #%c 对应输出该日志的类 #%L 对应输出该日志所在类对应的行号 log4j.appender.rootAppender.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ssS} %-5p [%t] %m (%.30c.%L)%n #自定义logger log4j.logger.com.ucweb.profile=warn,perfmt #仅打印日志到当前文件开关,不递归打印至父Logger中 #这个开关默认是开启(递归打日志到父Logger),强烈建议业务关闭这个开关; log4j.additivity.com.ucweb.profile=false # Rolling files log4j.appender.perfmt=org.apache.log4j.RollingFileAppender log4j.appender.perfmt.File=logs/monitor.log log4j.appender.perfmt.MaxFileSize=20MB log4j.appender.perfmt.MaxBackupIndex=100 #如配置了Threshold这个属性项,它表示该Appender输出日志时,对应的级别阈值, #log4j先校验logger对应的日志级别,然后才使用Threshold对应的日志级别,为防止配置出错,建议非特殊情况,不要配置该属性项 #log4j.appender.perfmt.Threshold=info #这个配置项表示是否立即刷新日志内容到磁盘,默认是开启的,建议采用默认值 #log4j.appender.perfmt.immediateFlush=true log4j.appender.perfmt.layout=org.apache.log4j.PatternLayout log4j.appender.perfmt.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ssS} %-5p [%t] %m (%.30c.%L)%n #控制台 log4j.appender.console=org.apache.log4j.ConsoleAppender log4j.appender.console.layout=org.apache.log4j.PatternLayout log4j.appender.console.layout.ConversionPattern=[%d{yyyy-MM-dd HH:mm:ss}] %p ~ %m%n
加载方式:
- 启动阶段加载:
通过添加系统环境变量: log4j.configuration=指向对应log4j配置文件的url
- 运行过程中加载:
1)程序启动入口处,通过PropertyConfigurator.configure(),动态加载log4j配置文件; 2)Log4j自身支持定时检查配置文件是否修改,如修改会自动重新加载; 3)代码中通过log4j提供的API,修改对应日志级别
注意事项:
- 1)每个独立的业务(或子系统)应独立一个Logger,每个Logger独立写日志文件,这样各自业务日志相互独立,即方便问题定位,有提升日志处理效率
简单起见在编码设计阶段就通过包名做区分,比如如下业务: 论坛:com.ucweb.bbs 发号:com.ucweb.ka 门户:com.ucweb.game; 这样在设置logger时,通过如下配置,对应所有该包下的类默认都只输入到各自业务日志文件中:
#BBS日志 log4j.logger.com.ucweb.bbs=warn,bbsAppender log4j.additivity.com.ucweb.bbs=false log4j.appender.bbsAppender=org.apache.log4j.RollingFileAppender log4j.appender.bbsAppender.File=logs/bbs.log log4j.appender.bbsAppender.MaxFileSize=20MB log4j.appender.bbsAppender.MaxBackupIndex=100 log4j.appender.bbsAppender.layout=org.apache.log4j.PatternLayout log4j.appender.bbsAppender.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ssS} %-5p [%t] %m (%c.%L)%n #发号日志 log4j.logger.com.ucweb.ka=warn,kaAppender log4j.additivity.com.ucweb.ka=false log4j.appender.kaAppender=org.apache.log4j.RollingFileAppender log4j.appender.kaAppender.File=logs/ka.log log4j.appender.kaAppender.MaxFileSize=20MB log4j.appender.kaAppender.MaxBackupIndex=100 log4j.appender.kaAppender.layout=org.apache.log4j.PatternLayout log4j.appender.kaAppender.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ssS} %-5p [%t] %m (%c.%L)%n #门户日志 log4j.logger.com.ucweb.game=warn,gameAppender log4j.additivity.com.ucweb.game=false log4j.appender.gameAppender=org.apache.log4j.RollingFileAppender log4j.appender.gameAppender.File=logs/game.log log4j.appender.gameAppender.MaxFileSize=20MB log4j.appender.gameAppender.MaxBackupIndex=100 log4j.appender.gameAppender.layout=org.apache.log4j.PatternLayout log4j.appender.gameAppender.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ssS} %-5p [%t] %m (%c.%L)%n
- 2)关闭递归向父Logger中打印日志,通过log4j.additivity配置
- 3)配置Layout时,尽量输出如下信息:时间戳,线程名,类,方法,日志内容,行号;
- 4)线上环境禁止输出日志至控制台Appender;
- 5)线上环境,日志级别组号是warn以上级别;
日志打印注意事项
目前jws框架是通过slf4j日志接口对外提供日志输出,建议输出日志时,遵守如下日志编码规范:
规则1】非特殊情况下,获取日志示例统一用slf4j的LoggerFactory如下签名方法获取,目的是为了方便后续切换日志实现,同时也统一编码风格:
org.slf4j.LoggerFactory 对应如下签名方法: public static Logger getLogger(Class clazz) 且对应的日志实例最好定义成static final private static final Logger logger = LoggerFactory.getLogger(LogDemo.class);
规则2】禁止在打印日志代码中,掺杂业务逻辑操作,特别是修改缓存操作:下面示例中logicMap是业务缓存,编码者本意是想删除缓存中一元素,并通过日志做记录。但当系统日志级别调整为warn以上时,remove操作将不执行,这将产生致命性错误,且难定位
logicMap.put("danger", "danger"); if(logger.isWarnEnabled()) { logger.warn("rmv a value:{}", logicMap.remove("danger")); }
规则3】对吃掉异常的,一定要打印详细堆栈信息(特殊无需打印,需要代码中添加注释),如仅对异常做包装,之后再次向外抛出,则禁止打印堆栈信息,最多打印简单的定位信息即可;异常信息,必须用error级别打印:
try { //可能抛出异常的逻辑 } catch (Exception e) { //此处吃掉异常,需要将异常堆栈打印出来 logger.error("", e); }
规则4】在循环中直接输出日志信息,可以先通过StringBuilder(非StringBuffer)做日志收集操作,然后一次性输出日志,如待输出日志内容过长,需要做截断处理
StringBuilder sb = new StringBuilder(); String[] businessTmp = new String[BUS_LEN]; for (int i = 0, nLen = businessTmp.length; i < nLen; i++) { // 正常的业务流... // 异常业务需要日志收集 if (null == businessTmp[i] || businessTmp[i].isEmpty()) { sb.append(i).append(','); } } int sbLen = sb.length();// 一次性输出异常日志信息 if (sbLen > 0) { if (sbLen > 4096) { // 同时要看日志是否长度过长,则忽略后面的 logger.warn("empty bsnss index[{} ...]", sb.substring(0, 4096)); } else { logger.warn("empty bsnss index[{}]", sb.toString()); } }
规则5】对需要打印变量信息的,禁止直接通过“+”操作符连接变量信息段,尽量避免使用String.format()操作(会new Formatter()),请参考如下方式输出
// 打印单个变量 logger.warn("msg->{}", msg1); // 打印两个变量 logger.warn("msg1->{},msg2->{}", msg1, msg2); // 3)对打印三个及三个以上变量,也需要加级别使能判断,这样减少不必要的new if (logger.isWarnEnabled()) { // 将申请内存的操作放置到合适的位置 String[] msgArr = new String[] { msg1, msg2, msg3 }; logger.warn("msg1->{},msg2->{},msg3->", msgArr); }
规则6】对性能要求非常苛刻,且调用频繁的接口,记录关键日志一定做要精简,必要时,可能只打印错误码,错误码->错误信息对照在相应代码中注释;对需要输出性能损耗时间的,应该在一定阈值下再输出
// you get a message,the message is : logger.warn("u get a msg: {}", msg1); //404->资源不存在 logger.warn("err:{}","404"); long bt = System.currentTimeMillis();//需输出接好耗时时间 //do some work ... long ct = System.currentTimeMillis() - bt; //对大于1s的,才需通过日志记录 if(ct > 1000){ logger.warn("invk getUserInfo cost: {}",ct); }
附上对应日志级别使用建议:
debug:仅限于在开发阶段,用于调试业务逻辑;
info:用于记录一般性信息,比如某业务逻辑操作成功后,可打印一条info信息;
warn:重要定位信息,比如操作耗时,系统登录User ID等,这些信息对定位问题有很大帮助,因此要关键信息,都建议用Warn级别;
error:异常信息,非常重要信息。
常见的错误配置示例
- logger只配置日志级别,不配置对应appender,虽然默认可能会打印日志到rootLogger,但这种配置很难理解:
- 多业务logger输出至同一个文件,且递归打印至父Logger: