Log4j+Slf4j日志框架
- 日志输出简介
- 日志属性配置文件
- 什么是日志附加器?
- 常用的附加器实现类
- Log4j日志级别
- Slf4j 简介
- 测试日志输出
- 业务中日志正确打印
- 1. 选择恰当的日志级别
- 2. 日志要打印出方法的入参、出参
- 3. 选择合适的日志格式
- 4. 遇到if...else...等条件时,每个分支首行都尽量打印日志
- 5.日志级别比较低时,进行日志开关判断
- 6. 不能直接使用日志系统(Log4j、Logback)中的 API,而是使用日志框架SLF4J中的API。
- 7. 建议使用参数占位{},而不是用+拼接。
- 8. 建议使用异步的方式来输出日志。
- 9. 不要使用e.printStackTrace()
- 10. 异常日志不要只打一半,要输出全部错误信息
- 11. 禁止在线上环境开启 debug
- 12.不要记录了异常,又抛出异常
- 13.避免重复打印日志
- 14.日志文件分离
- 15. 核心功能模块,建议打印较完整的日志
日志输出简介
Log4j 的日志输出控制文件,主要由三个部分构成:
- 日志信息的输出位置:控制日志信息将要输出的位置,是控制台还是文件等。
- 日志信息的输出格式:控制日志信息的显示格式,即以怎样的字符串形式显示。
- 日志信息的输出级别:控制日志信息的显示内容,即显示哪些级别的日志信息。
- 有了日志输出控制文件,代码中只要设置好日志信息内容及其级别即可,通过控制文件便可控制这些日志信息的输出了。
日志属性配置文件
日志属性文件 log4j.properties
是专门用于控制日志输出的。其主要进行三方面控制:
- 输出位置:控制日志将要输出的位置,是控制台还是文件等。
- 输出布局:控制日志信息的显示形式。
- 输出级别:控制要输出的日志级别。
- 日志属性文件由两个对象组成:日志附加器与根日志。
根日志,即为 Java 代码中的日志记录器,其主要由两个属性构成:日志输出级别与日志附加器。
日志附加器,则由日志输出位置定义,由其它很多属性进行修饰,如输出布局、文件位置、文件大小等。
什么是日志附加器?
所谓日志附加器,就是为日志记录器附加上很多其它设置信息。附加器的本质是一个接口,其定义语法为:log4j.appender.appenderName
= 输出位置
常用的附加器实现类
- org.apache.log4j.ConsoleAppender:日志输出到控制台
- org.apache.log4j.FileAppender:日志输出到文件
- org.apache.log4j.RollingFileAppender:当日志文件大小到达指定尺寸的时候将产生一个新的日志文件
- org.apache.log4j.DailyRollingFileAppender:每天产生一个日志文件
#常用布局类型 - org.apache.log4j.HTMLLayout:网页布局,以 HTML 表格形式布局
- org.apache.log4j.SimpleLayout:简单布局,包含日志信息的级别和信息字符串
- org.apache.log4j.PatternLayout:匹配器布局,可以灵活地指定布局模式。其主要是通过设置 PatternLayout 的 ConversionPattern 属性值来控制具体输出格式的 。
打印参数: Log4J 采用类似 C 语言中的 printf 函数的打印格式格式化日志信息 - %m:输出代码中指定的消息
- %p:输出优先级,即 DEBUG,INFO,WARN,ERROR,FATAL
- %r:输出自应用启动到输出该 log 信息耗费的毫秒数
- %c:输出所属的类目,通常就是所在类的全名
- %t:输出产生该日志事件的线程名
- %n:输出一个回车换行符,Windows 平台为 /r/n,Unix 平台为 /n
- %d:输出日志时间点的日期或时间,默认格式为 ISO8601,也可以在其后指定格式,比如:%d{yyy MMM dd HH:mm:ss , SSS},输出类似:2002年10月18日 22:10:28,921
- %l:输出日志事件的发生位置,包括类目名、发生的线程,以及在代码中的行数。举例:Testlog4.main(TestLog4.java: 10 )
Log4j日志级别
一个完整的软件,日志是必不可少的。程序从开发、测试、维护、运行等环节,都需要向控制台或文件等位置输出大量信息。这些信息的输出, 在很多时候是使用System.out.println()
无法完成的。
日志信息根据用途与记录内容的不同,分为调试日志、运行日志、异常日志 等。
Log4j 的全称为 Log for java,即专门用于 Java 语言的日志记录工具。
日志级别
为了方便对于日志信息的输出显示,对日志内容进行了分级管理。日志级别由高到低,共分 6 个级别:
- fatal(致命的)
- error
- warn
- info
- debug
- trace(堆栈)
为什么要对日志进行分级
无论是将日志输出到控制台,还是文件,其输出都会降低程序的运行效率。但由于调试、运行维护的需要,客户的要求等原因,需要进行必要的日志输出。这时就必须要在代码中加入日志输出语句。
这些输出语句若在程序运行时全部执行, 则势必会降低运行效率。例如, 使用 System.out.println() 将信息输出到控制台,则所有的该输出语句均将执行。会大大降低程序的执行效率。而要使其不输出,唯一的办法就是将这些输出语句逐个全部删除。这是个费时费力的过程。
将日志信息进行分级管理,便可方便的控制信息输出内容及输出位置:哪些信息需要输出,哪些信息不需要输出,只需在一个日志输出控制文件中稍加修改即可。而代码中的输出语句不用做任何修改。
从这个角度来说,代码中的日志编写,其实就是写大量的输出语句。只不过,这些输出语句比较特殊,它们具有级别,在程序运行期间不一定被执行。它们的执行是由另一个控制文件控制。
Slf4j 简介
slf4j 的全称是 Simple Loging Facade For Java,即它仅仅是一个为 Java 程序提供日志输出的统一接口,并不是一个具体的日志实现方案,就比如 JDBC 一样,只是一种规则而已。所以单独的 slf4j 是不能工作的,必须搭配其他具体的日志实现方案,比如 apache 的 org.apache.log4j.Logger,JDK 自带的 java.util.logging.Logger 以及 log4j 等。
POM
继续之前的项目,pom.xml
配置如下:
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<groupId>com.zysheep</groupId>
<artifactId>hello-spring</artifactId>
<version>1.0.0-SNAPSHOT</version>
<packaging>jar</packaging>
<dependencies>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-context</artifactId>
<version>4.3.17.RELEASE</version>
</dependency>
<dependency>
<groupId>junit</groupId>
<artifactId>junit</artifactId>
<version>4.12</version>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.25</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.7.25</version>
</dependency>
</dependencies>
</project>
主要增加了 org.slf4j:slf4j-log4j12
依赖
直接引用,不用其他框架整合使用
<dependency>
<groupId>log4j</groupId>
<artifactId>log4j</artifactId>
<version>1.2.17</version>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-log4j12</artifactId>
<version>1.7.36</version>
</dependency>
依赖中出现这种错误,说明SLF4J日志门面有多种实现,这里指logback和log4j,需要排除一种实现即可
解决多种日志实现的冲突
创建 log4j.properties
配置文件
在 src/main/resources
目录下创建名为 log4j.properties
的属性配置文件,配置文件内容如下:按自己的格式选择任何一种都可以
# 根日志,配置了日志级别为 INFO,预定义了名称为 console、file 两种附加器
log4j.rootLogger=INFO, console, file
# 指定包目录输出不同级别的日志
log4j.logger.cn.zysheep.mapper=debug, console, file
log4j.additivity.cn.zysheep.mapper=false
# console 附加器,日志输出位置在控制台
log4j.appender.console=org.apache.log4j.ConsoleAppender
# console 附加器,采用匹配器布局模式
log4j.appender.console.layout=org.apache.log4j.PatternLayout
# console 附加器,日志输出格式为:日期 日志级别 [类名] - 消息换行符
log4j.appender.console.layout.ConversionPattern=%d %p [%c] - %m%n
# file 附加器,每天产生一个日志文件
log4j.appender.file=org.apache.log4j.DailyRollingFileAppender
# file 附加器,日志文件输出位置 logs/log.log
log4j.appender.file.File=logs/log.log
# file 附加器,采用匹配器布局模式
log4j.appender.file.layout=org.apache.log4j.PatternLayout
# 日志文件最大值
log4j.appender.A3.MaxFileSize=1024KB
# 最多纪录文件数
log4j.appender.A3.MaxBackupIndex=10
# file 附加器,日志输出格式为:日期 日志级别 [类名] - 消息换行符
log4j.appender.file.layout.ConversionPattern=%d %p [%c] - %m%n
控制台输出格式:
#指定输出日志信息的级别与输出的位置
#日志级别,包括 TRACE < DEBUG < INFO < WARN < ERROR .
#console 表示下面的控制台,logFile 表示下面的日志文件.
log4j.rootLogger=DEBUG,console,logFile
#表示Logger不会在父Logger的appender里输出,默认为true
log4j.additivity.org.apache=true
#控制台
log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.layout=org.apache.log4j.PatternLayout
log4j.appender.console.ImmediateFlush=true
log4j.appender.console.Target=System.err
#日志输出的格式
log4j.appender.console.layout.ConversionPattern=%5p [%t] (%c:%L) %d{yyyy-MM-dd HH:mm:ss,SSS} ---- %m%n
#日志文件
log4j.appender.logFile=org.apache.log4j.FileAppender
log4j.appender.logFile.Threshold=DEBUG
log4j.appender.logFile.ImmediateFlush=true
log4j.appender.logFile.Append=true
#日志文件存放的路径
log4j.appender.logFile.File=E:/logs/log.log4j
log4j.appender.logFile.layout=org.apache.log4j.PatternLayout
#日志输出的格式
log4j.appender.logFile.layout.ConversionPattern=[%-5p] %d(%r) --> [%t] %l: %m %x %n
控制台打印格式:
测试日志输出
创建一个测试类,并测试日志输出效果,代码如下:
package com.zysheep.hello.spring;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class MyTest {
public static final Logger logger = LoggerFactory.getLogger(MyTest.class);
public static void main(String[] args) {
logger.info("slf4j for info");
logger.debug("slf4j for debug");
logger.error("slf4j for error");
logger.warn("slf4j for warn");
String message = "Hello SLF4J";
logger.info("slf4j message is : {}", message);
}
}
此时控制台显示为:
2019-06-07 05:15:42,914 INFO [com.zysheep.hello.spring.MyTest] - slf4j for info
2019-06-07 05:15:42,915 ERROR [com.zysheep.hello.spring.MyTest] - slf4j for error
2019-06-07 05:15:42,915 WARN [com.zysheep.hello.spring.MyTest] - slf4j for warn
2019-06-07 05:15:42,916 INFO [com.funtl.hello.spring.MyTest] - slf4j message is : Hello SLF4J
项目根目录下也会多出 logs/log.log 目录及文件
附:占位符说明
打日志的时候使用了 {} 占位符,这样就不会有字符串拼接操作,减少了无用 String
对象的数量,节省了内存。并且,记住,在生产最终日志信息的字符串之前,这个方法会检查一个特定的日志级别是不是打开了,这不仅降低了内存消耗而且预先降低了CPU
去处理字符串连接命令的时间。\
业务中日志正确打印
1. 选择恰当的日志级别
常见的日志级别有5种,分别是error、warn、info、debug、trace。日常开发中,我们需要选择恰当的日志级别,不要反手就是打印info哈~
- error:错误日志,指比较严重的错误,对正常业务有影响,需要运维配置监控的;
- warn:警告日志,一般的错误,对业务影响不大,但是需要开发关注;
- info:信息日志,记录排查问题的关键信息,如调用时间、出参入参等等;
- debug:用于开发DEBUG的,关键逻辑里面的运行时数据;
- trace:最详细的信息,一般这些信息只记录到日志文件中。
2. 日志要打印出方法的入参、出参
我们并不需要打印很多很多日志,只需要打印可以快速定位问题的有效日志。有效的日志,是甩锅的利器!
哪些算得的上有效关键的日志呢?比如说,方法进来的时候,打印入参。再然后呢,在方法返回的时候,就是打印出参,返回值。入参的话,一般就是userId或者bizSeq这些关键信息。正例如下:
public String testLogMethod(Document doc, Mode mode){
log.debug(“method enter param:{}”,userId);
String id = "666";
log.debug(“method exit param:{}”,id);
return id;
}
3. 选择合适的日志格式
理想的日志格式,应当包括这些最基本的信息:如当前时间戳(一般毫秒精确度)、日志级别,线程名字等等。在logback日志里可以这么配置:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} %-5level [%thread][%logger{0}] %m%n</pattern>
</encoder>
</appender>
如果我们的日志格式,连当前时间都沒有记录,那连请求的时间点都不知道了?
4. 遇到if…else…等条件时,每个分支首行都尽量打印日志
当你碰到if…else…或者switch这样的条件时,可以在分支的首行就打印日志,这样排查问题时,就可以通过日志,确定进入了哪个分支,代码逻辑更清晰,也更方便排查问题了。
正例:
if(user.isVip()){
log.info("该用户是会员,Id:{},开始处理会员逻辑",user,getUserId());
//会员逻辑
}else{
log.info("该用户是非会员,Id:{},开始处理非会员逻辑",user,getUserId())
//非会员逻辑
}
5.日志级别比较低时,进行日志开关判断
对于trace/debug这些比较低的日志级别,必须进行日志级别的开关判断。
正例:
User user = new User(666L, "公众号", "捡田螺的小男孩");
if (log.isDebugEnabled()) {
log.debug("userId is: {}", user.getId());
}
因为当前有如下的日志代码:
logger.debug("Processing trade with id: " + id + " and symbol: " + symbol);
如果配置的日志级别是warn的话,上述日志不会打印,但是会执行字符串拼接操作,如果symbol
是对象, 还会执行toString()
方法,浪费了系统资源,执行了上述操作,最终日志却没有打印,因此建议加日志开关判断。
6. 不能直接使用日志系统(Log4j、Logback)中的 API,而是使用日志框架SLF4J中的API。
SLF4J 是门面模式的日志框架,有利于维护和各个类的日志处理方式统一,并且可以在保证不修改代码的情况下,很方便的实现底层日志框架的更换。
正例:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
private static final Logger logger = LoggerFactory.getLogger(TianLuoBoy.class);
7. 建议使用参数占位{},而不是用+拼接。
反例:
logger.info("Processing trade with id: " + id + " and symbol: " + symbol);
上面的例子中,使用+
操作符进行字符串的拼接,有一定的性能损耗。
正例如下:
logger.info("Processing trade with id: {} and symbol : {} ", id, symbol);
我们使用了大括号{}
来作为日志中的占位符,比于使用+
操作符,更加优雅简洁。并且,相对于反例,使用占位符仅是替换动作,可以有效提升性能。
8. 建议使用异步的方式来输出日志。
- 日志最终会输出到文件或者其它输出流中的,IO性能会有要求的。如果异步,就可以显著提升IO性能。
- 除非有特殊要求,要不然建议使用异步的方式来输出日志。以logback为例吧,要配置异步很简单,使用AsyncAppender就行
<appender name="FILE_ASYNC" class="ch.qos.logback.classic.AsyncAppender">
<appender-ref ref="ASYNC"/>
</appender>
9. 不要使用e.printStackTrace()
反例:
try{
// 业务代码处理
}catch(Exception e){
e.printStackTrace();
}
正例:
try{
// 业务代码处理
}catch(Exception e){
log.error("你的程序有异常啦",e);
}
理由:
- e.printStackTrace()打印出的堆栈日志跟业务代码日志是交错混合在一起的,通常排查异常日志不太方便。
- e.printStackTrace()语句产生的字符串记录的是堆栈信息,如果信息太长太多,字符串常量池所在的内存块没有空间了,即内存满了,那么,用户的请求就卡住啦~
10. 异常日志不要只打一半,要输出全部错误信息
反例1:
try {
//业务代码处理
} catch (Exception e) {
// 错误
LOG.error('你的程序有异常啦');
}
- 异常e都没有打印出来,所以压根不知道出了什么类型的异常。
反例2:
try {
//业务代码处理
} catch (Exception e) {
// 错误
LOG.error('你的程序有异常啦', e.getMessage());
}
e.getMessage()
不会记录详细的堆栈异常信息,只会记录错误基本描述信息,不利于排查问题。
正例:
try {
//业务代码处理
} catch (Exception e) {
// 错误
LOG.error('你的程序有异常啦', e);
}
11. 禁止在线上环境开启 debug
禁止在线上环境开启debug,这一点非常重要。
因为一般系统的debug日志会很多,并且各种框架中也大量使用 debug的日志,线上开启debug不久可能会打满磁盘,影响业务系统的正常运行。
12.不要记录了异常,又抛出异常
反例如下:
log.error("IO exception", e);
throw new MyException(e);
- 这样实现的话,通常会把栈信息打印两次。这是因为捕获了MyException异常的地方,还会再打印一次。
- 这样的日志记录,或者包装后再抛出去,不要同时使用!否则你的日志看起来会让人很迷惑。
13.避免重复打印日志
避免重复打印日志,酱紫会浪费磁盘空间。如果你已经有一行日志清楚表达了意思,避免再冗余打印,反例如下:
if(user.isVip()){
log.info("该用户是会员,Id:{}",user,getUserId());
//冗余,可以跟前面的日志合并一起
log.info("开始处理会员逻辑,id:{}",user,getUserId());
//会员逻辑
}else{
//非会员逻辑
}
如果你是使用log4j日志框架,务必在log4j.xml
中设置 additivity=false,因为可以避免重复打印日志
正例:
<logger name="com.taobao.dubbo.config" additivity="false">
14.日志文件分离
- 我们可以把不同类型的日志分离出去,比如access.log,或者error级别error.log,都可以单独打印到一个文件里面。
- 当然,也可以根据不同的业务模块,打印到不同的日志文件里,这样我们排查问题和做数据统计的时候,都会比较方便啦。
15. 核心功能模块,建议打印较完整的日志
- 我们日常开发中,如果核心或者逻辑复杂的代码,建议添加详细的注释,以及较详细的日志。
- 日志要多详细呢?脑洞一下,如果你的核心程序哪一步出错了,通过日志可以定位到,那就可以啦。