# Log

back2专题

----Logger必须作为类的静态变量使用----

# springboot日志

# 配置根Logger

 log4j.rootLogger  =   [ level ]   ,  appenderName1 ,  appenderName2 ,
1

# 配置日志信息输出目的地Appender

返回顶部

 log4j.appender.appenderName  =  fully.qualified.name.of.appender.class
   log4j.appender.appenderName.option1  =  value1
   …
   log4j.appender.appenderName.optionN  =  valueN
1
2
3
4

# 配置日志信息的格式(布局)

 log4j.appender.appenderName.layout  =  fully.qualified.name.of.layout.class
   log4j.appender.appenderName.layout.option1  =  value1
   …
   log4j.appender.appenderName.layout.optionN  =  valueN
1
2
3
4
  • 其中 [level] 是日志输出级别,共有5级:
级别 码值
OFF 0
FATAL 0
ERROR 3
WARN 4
INFO 6
DEBUG 7
  • Appender 为日志输出目的地,Log4j提供的appender有以下几种:
 org.apache.log4j.ConsoleAppender(控制台),
 org.apache.log4j.FileAppender(文件),
 org.apache.log4j.DailyRollingFileAppender(每天产生一个日志文件),
 org.apache.log4j.RollingFileAppender(文件大小到达指定尺寸的时候产生一个新的文件),
 org.apache.log4j.WriterAppender(将日志信息以流格式发送到任意指定的地方)
1
2
3
4
5
  • Layout:日志输出格式,Log4j提供的layout有以下几种:
 org.apache.log4j.HTMLLayout(以HTML表格形式布局),
 org.apache.log4j.PatternLayout(可以灵活地指定布局模式),
 org.apache.log4j.SimpleLayout(包含日志信息的级别和信息字符串),
 org.apache.log4j.TTCCLayout(包含日志产生的时间、线程、类别等等信息)
1
2
3
4
  • 打印参数: 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 )

# 在代码中初始化Logger

back

1)在程序中调用BasicConfigurator.configure()方法:给根记录器增加一个ConsoleAppender,输出格式通过PatternLayout设为"%-4r [%t] %-5p %c %x - %m%n",还有根记录器的默认级别是Level.DEBUG.
2)配置放在文件里,通过命令行参数传递文件名字,通过PropertyConfigurator.configure(args[x])解析并配置;
3)配置放在文件里,通过环境变量传递文件名等信息,利用log4j默认的初始化过程解析并配置;
4)配置放在文件里,通过应用服务器配置传递文件名等信息,利用一个特殊的servlet来完成配置。

# 为不同的Appender设置日志输出级别

back

当调试系统时,我们往往注意的只是异常级别的日志输出,但是通常所有级别的输出都是放在一个文件里的,如果日志输出的级别是BUG!?那就慢慢去找吧。 这时我们也许会想要是能把异常信息单独输出到一个文件里该多好啊。当然可以,Log4j已经提供了这样的功能,我们只需要在配置中修改Appender的Threshold就能实现,比如下面的例子:

# 配置文件

 ### set log levels ###
 log4j.rootLogger = debug ,  stdout ,  D ,  E

 ### 输出到控制台 ###
 log4j.appender.stdout = org.apache.log4j.ConsoleAppender
 log4j.appender.stdout.Target = System.out
 log4j.appender.stdout.layout = org.apache.log4j.PatternLayout
 log4j.appender.stdout.layout.ConversionPattern =  %d{ABSOLUTE} %5p %c{ 1 }:%L - %m%n

 ### 输出到日志文件 ###
 log4j.appender.D = org.apache.log4j.DailyRollingFileAppender
 log4j.appender.D.File = logs/log.log
 log4j.appender.D.Append = true
 log4j.appender.D.Threshold = DEBUG ## 输出DEBUG级别以上的日志
 log4j.appender.D.layout = org.apache.log4j.PatternLayout
 log4j.appender.D.layout.ConversionPattern = %-d{yyyy-MM-dd HH:mm:ss}  [ %t:%r ] - [ %p ]  %m%n

 ### 保存异常信息到单独文件 ###
 log4j.appender.D = org.apache.log4j.DailyRollingFileAppender
 log4j.appender.D.File = logs/error.log ## 异常日志文件名
 log4j.appender.D.Append = true
 log4j.appender.D.Threshold = ERROR ## 只输出ERROR级别以上的日志!!!
 log4j.appender.D.layout = org.apache.log4j.PatternLayout
 log4j.appender.D.layout.ConversionPattern = %-d{yyyy-MM-dd HH:mm:ss}  [ %t:%r ] - [ %p ]  %m%n
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24

# sl4j与log4j

back

# 基本介绍

SLF4J不同于其他日志类库,与其它日志类库有很大的不同。SLF4J(Simple logging Facade for Java)不是一个真正的日志实现,而是一个抽象层( abstraction layer),它允许你在后台使用任意一个日志类库。如果是在编写供内外部都可以使用的API或者通用类库,那么你真不会希望使用你类库的客户端必须使用你选择的日志类库。

如果一个项目已经使用了log4j,而你加载了一个类库,比方说 Apache Active MQ——它依赖于于另外一个日志类库logback,那么你就需要把它也加载进去。但如果Apache Active MQ使用了SLF4J,你可以继续使用你的日志类库而无需忍受加载和维护一个新的日志框架的痛苦。
  总的来说,SLF4J使你的代码独立于任意一个特定的日志API,这是对于API开发者的很好的思想。虽然抽象日志类库的思想已经不是新鲜的事物,而且Apache commons logging也已经在使用这种思想了,但SLF4J正迅速成为Java世界的日志标准。让我们再看几个使用SLF4J而不是log4j、logback或者java.util.logging的理由。

# SLF4J对比Log4J,logback和java.util.Logging的优势

正如我之前说的,在你的代码中使用SLF4J写日志语句的主要出发点是使得你的程序独立于任何特定的日志类库,依赖于特定类库可能需要使用不同于你已有的配置,并且导致更多维护的麻烦。除此之外,还有一个SLF4J API的特性是使得我坚持使用SLF4J而抛弃我长期间钟爱的Log4j的理由,是被称为占位符(place holder),在代码中表示为“{}”的特性。
占位符是一个非常类似于在String的format()方法中的%s,因为它会在运行时被某个提供的实际字符串所替换。这不仅降低了你代码中字符串连接次数,而且还节省了新建的String对象。通过使用SLF4J,你可以在运行时延迟字符串的建立,这意味着只有需要的String对象才被建立。而如果你已经使用log4j,那么你已经对于在if条件中使用debug语句这种变通方案十分熟悉了,但SLF4J的占位符就比这个好用得多。

# log4j

Apache 的一个开放源代码项目,通过使用Log4j,我们可以控制日志信息输送的目的地是控制台、文件、GUI组件、甚至是套接口服务 器、NT的事件记录器、UNIX Syslog守护进程等;用户也可以控制每一条日志的输出格式;通过定义每一条日志信息的级别,用户能够更加细致地控制日志的生成过程。这些可以通过一个 配置文件来灵活地进行配置,而不需要修改程序代码

<dependency>
 <groupId>log4j</groupId>
 <artifactId>log4j</artifactId>
 <version>1.2.17</version>
</dependency>
1
2
3
4
5

# Logback

是由 log4j 创始人设计的又一个开源日记组件,Logback 当前分成三个模块:logback-core,logback- classic和logback-access。logback-core是其它两个模块的基础模块,logback-classic是log4j的一个 改良版本。此外logback-classic 完整实现 SLF4J API 使你可以很方便地更换成其它日记系统如log4j或JDK14 Logging。logback-access访问模块与Servlet容器集成提供通过Http来访问日记的功能

<dependency>
 <groupId>ch.qos.logback</groupId>
 <artifactId>logback-core</artifactId>
 <version>1.1.6</version>
</dependency>
<dependency>
 <groupId>ch.qos.logback</groupId>
 <artifactId>logback-classic</artifactId>
 <version>1.1.6</version>
</dependency>
<dependency>
 <groupId>org.slf4j</groupId>
 <artifactId>slf4j-api</artifactId>
 <version>1.7.18</version>
</dependency>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

# Slf4j

<dependency>
 <groupId>org.slf4j</groupId>
 <artifactId>slf4j-api</artifactId>
 <version>1.7.13</version>
 </dependency>
1
2
3
4
5

# slf4j的简单用法

类似配置log4j.properties

# 关于正式开发中的日记记录的方法:(重要)

back

项目中日志记录还是有很多说法的,比如保存日志级别,日志应该打印的信息,日志参数的设置等:

  • 一般是将捕捉到的Exception对象作为日志记录的最后一个参数(会显示具体的出错信息以及出错位置),而且要放在{}可以格式化的参数之外,防止被{}转为e.toString()
log.error("can found file [{}]", filePath, e);
1

结果:

2018-08-18 10:50:03 [cn.xm.exam.test.Slf4jTest]-[ERROR] can found file [xxxxxx]
    java.io.FileNotFoundException: xxxxxx (系统找不到指定的文件。)
        at java.io.FileInputStream.open(Native Method)
        at java.io.FileInputStream.<init>(FileInputStream.java:146)
        at cn.xm.exam.test.Slf4jTest.openFile(Slf4jTest.java:22)
        at cn.xm.exam.test.Slf4jTest.main(Slf4jTest.java:16)
1
2
3
4
5
6

注意: {}的作用是调用对应参数的toString()方法格式化日志,如果exception放在对应参数的位置上也会被格式化。所以,e要放在{}参数之外,而且只能放在最后一个。
如果放在中间也不会被打印错误信息:只要放到{}之外的最后一个参数就可以打印错误信息(包括信息和位置)

log.error("error:can found file [{}]", filePath, 3, e);
1

放到{}之外的非最后一个参数不会打印错误信息

log.error("error:can found file [{}]", filePath,e,3);
1

结果:

2018-08-18 11:10:38 [cn.xm.exam.test.Slf4jTest]-[ERROR] error:can found file [xxxxxx]
1

尽量不使用e.getMessage(),因为有的异常不一定有message,可以使用e.toString只会显示信息,不会显示出错的位置信息(不建议这种)

补充:Threshold还可以指定输出的日志级别: (如果设置不起作用查看项目是不是用的log4j的包,有可能有多个log4j包,造成冲突) 有时候我们需要把一些报错ERROR日志单独存到指定文件 ,这时候,Threshold属性就派上用场了,比如:

当然这里有个提前 rootLogger里配置的level必须小于Threshold等级,否则无效 还是按照总的rootLogger里的level来输出,一般我们实际实用的话 rootLogger里配置DEBUG,然后某个文件专门存储ERRO日志,就配置下Threshold为ERROR

补充:log4j也可以对不同的包进行不同的配置,也就是针对不同的包采用不同的日志级别与日志控制器 有时候我们也希望对不同的包采用不通的日志记录级别以及不同的日志记录方式。log4j完全可以做到这点,例如下面

默认包采用rootLogger的配置,info级别、在控制台与文件中进行显示;同时又修改了cn下面的a、b、c包的日志级别:

cn.a只降低了级别为debug,输出方式还是console与file两种。(一般我们采用这种方式修改级别即可,如果再设置输出方式会在原来的基础上增加方式)

cn.b级别设为info,方式设为console,实际是加了第三种方式

cn.c级别设置为error,方式设为file,实际也是在rootLogger基础上增加第三种方式

级别会以log4j.logger.XX级别为准,不管rootLogger级别高于对具体包的设置还是低于具体包的设置;输出方式会在rootLogger的基础上增加新的方式,如果没有额外的方式采用rootLogger的方式。

例如:(注意标红地方)

log4j.rootLogger=info,console,file

log4j.logger.cn.a=debug
log4j.logger.cn.b=info,console
log4j.logger.cn.c=error,file

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} [%c]-[%p] %m%n

log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=E:\\test.log
log4j.appender.file.MaxFileSize=10MB
log4j.appender.file.MaxBackupIndex=5
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} [%c]-[%p] %m%n
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

补充:对父包设置日志级别,如果子包没有设置默认采用父包的设置,如果子包设置了会采用单独的设置 配置修改cn包设置以及对b包单独进行设置:

log4j.logger.cn=error
log4j.logger.cn.b=info,console
1
2

补充:上面的对包的具体设置日志级别虽然不受总的log4j.rootLogger的日志级别的限制,但是却受特殊的日志的Threshold属性的限制,也就是对具体包的设置必须高于其记录器的Threshold属性,否则以其记录器的Threshold属性为准 例如:修改上面的日志配置(每个日志记录器增加Threshold属性)

log4j.rootLogger=info,console,file

log4j.logger.cn.a=debug
log4j.logger.cn.b=info,console
log4j.logger.cn.c=error,file

log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.Threshold=info
log4j.appender.console.layout=org.apache.log4j.PatternLayout
log4j.appender.console.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} [%c]-[%p] %m%n

log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.Threshold=error
log4j.appender.file.File=E:\\test.log
log4j.appender.file.MaxFileSize=10MB
log4j.appender.file.MaxBackupIndex=5
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} [%c]-[%p] %m%n
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

运行AC1:

2018-11-12 23:03:08 [cn.a.AC1]-[INFO] AC1
2018-11-12 23:03:08 [cn.a.AC1]-[ERROR] AC1
1
2

运行BC1:

2018-11-12 23:03:33 [cn.b.BC1]-[INFO] BC1
2018-11-12 23:03:33 [cn.b.BC1]-[INFO] BC1
2018-11-12 23:03:33 [cn.b.BC1]-[ERROR] BC1
2018-11-12 23:03:33 [cn.b.BC1]-[ERROR] BC1
1
2
3
4

所以总结上面的日记记录级别的设置优先级可以总结为:Threshold > 具体包的设置 > rootLogger的全局配置

# 打日志的正确姿势

back

# 使用slf4j

使用门面模式的日志框架,有利于维护和各个类的日志处理方式统一。
实现方式统一使用: Logback框架

# 什么时候应该打日志

  • 当你遇到问题的时候,只能通过debug功能来确定问题,你应该考虑打日志,良好的系统,是可以通过日志进行问题定为的。
  • 当你碰到if…else 或者 switch这样的分支时,要在分支的首行打印日志,用来确定进入了哪个分支
  • 经常以功能为核心进行开发,你应该在提交代码前,可以确定通过日志可以看到整个流程

# 基本格式

必须使用参数化信息的方式:

logger.debug("Processing trade with id:[{}] and symbol : [{}] ", id, symbol);
1

对于debug日志,必须判断是否为debug级别后,才进行使用:

if (logger.isDebugEnabled()) {
    logger.debug("Processing trade with id: " +id + " symbol: " + symbol);
}
1
2
3

不要进行字符串拼接,那样会产生很多String对象,占用空间,影响性能。

  • 反例(不要这么做):
//反例
logger.debug("Processing trade with id: " + id + " symbol: " + symbol);
1
2

使用[]进行参数变量隔离
如有参数变量,应该写成如下写法:

logger.debug("Processing trade with id:[{}] and symbol : [{}] ", id, symbol);
1

这样的格式写法,可读性更好,对于排查问题更有帮助。

# ERROR

  • 基本概念

影响到程序正常运行、当前请求正常运行的异常情况:

  1. 打开配置文件失败
  2. 所有第三方对接的异常(包括第三方返回错误码)
  3. 所有影响功能使用的异常,包括:SQLException和除了业务异常之外的所有异常(RuntimeException和Exception)

不应该出现的情况:

  1. 比如要使用Azure传图片,但是Azure未响应

如果有Throwable信息,需要记录完成的堆栈信息:

log.error("获取用户[{}]的用户信息时出错",userName,e);
1

如果进行了抛出异常操作,请不要记录error日志由最终处理方进行处理

  • 反例(不要这么做):
//反例
try{
    ....
}catch(Exception ex){
  String errorMessage=String.format("Error while reading information of user [%s]",userName);
  logger.error(errorMessage,ex);
  throw new UserServiceException(errorMessage,ex);
}
1
2
3
4
5
6
7
8

# WARN

  • 基本概念

不应该出现但是不影响程序、当前请求正常运行的异常情况:

  1. 有容错机制的时候出现的错误情况
  2. 找不到配置文件,但是系统能自动创建配置文件

即将接近临界值的时候,例如:

  1. 缓存池占用达到警告线

业务异常的记录,比如:

  1. 当接口抛出业务异常时,应该记录此异常

# INFO

  • 基本概念

系统运行信息

  1. Service方法中对于系统/业务状态的变更
  2. 主要逻辑中的分步骤

外部接口部分

  1. 客户端请求参数(REST/WS)
  2. 调用第三方时的调用参数和调用结果
  • 并不是所有的service都进行出入口打点记录,单一、简单service是没有意义的(job除外,job需要记录开始和结束,)。

反例(不要这么做):

public List listByBaseType(Integer baseTypeId) {


   log.info("开始查询基地");
BaseExample ex=new BaseExample();
BaseExample.Criteria ctr = ex.createCriteria();
ctr.andIsDeleteEqualTo(IsDelete.USE.getValue());
Optionals.doIfPresent(baseTypeId, ctr::andBaseTypeIdEqualTo);
   log.info("查询基地结束");
return baseRepository.selectByExample(ex);
}
1
2
3
4
5
6
7
8
9
10
11
  1. 对于复杂的业务逻辑,需要进行日志打点,以及埋点记录,比如电商系统中的下订单逻辑,以及OrderAction操作(业务状态变更)。
  2. 对于整个系统的提供出的接口(REST/WS),使用info记录入参
  3. 如果所有的service为SOA架构,那么可以看成是一个外部接口提供方,那么必须记录入参。
  4. 调用其他第三方服务时,所有的出参和入参是必须要记录的(因为你很难追溯第三方模块发生的问题)

# DEBUG

  • 基本概念
  1. 可以填写所有的想知道的相关信息(但不代表可以随便写,debug信息要有意义,最好有相关参数)
  2. 生产环境需要关闭DEBUG信息
  3. 如果在生产情况下需要开启DEBUG,需要使用开关进行管理,不能一直开启。
  • 如果代码中出现以下代码,可以进行优化:
//1. 获取用户基本薪资

//2. 获取用户休假情况

//3. 计算用户应得薪资
1
2
3
4
5

优化后的代码:

logger.debug("开始获取员工[{}] [{}]年基本薪资",employee,year);

logger.debug("获取员工[{}] [{}]年的基本薪资为[{}]",employee,year,basicSalary);
logger.debug("开始获取员工[{}] [{}]年[{}]月休假情况",employee,year,month);

logger.debug("员工[{}][{}]年[{}]月年假/病假/事假为[{}]/[{}]/[{}]",employee,year,month,annualLeaveDays,sickLeaveDays,noPayLeaveDays);
logger.debug("开始计算员工[{}][{}]年[{}]月应得薪资",employee,year,month);

logger.debug("员工[{}] [{}]年[{}]月应得薪资为[{}]",employee,year,month,actualSalary);
1
2
3
4
5
6
7
8
9

# TRACE

  • 基本概念

特别详细的系统运行完成信息,业务代码中,不要使用.(除非有特殊用意,否则请使用DEBUG级别替代)

规范示例说明

@Override
@Transactional
public void createUserAndBindMobile(@NotBlank String mobile, @NotNull User user) throws CreateConflictException{
    boolean debug = log.isDebugEnabled();
    if(debug){
        log.debug("开始创建用户并绑定手机号. args[mobile=[{}],user=[{}]]", mobile, LogObjects.toString(user));
    }
    try {
        user.setCreateTime(new Date());
        user.setUpdateTime(new Date());
        userRepository.insertSelective(user);
        if(debug){
            log.debug("创建用户信息成功. insertedUser=[{}]",LogObjects.toString(user));
        }
        UserMobileRelationship relationship = new UserMobileRelationship();
        relationship.setMobile(mobile);
        relationship.setOpenId(user.getOpenId());
        relationship.setCreateTime(new Date());
        relationship.setUpdateTime(new Date());
        userMobileRelationshipRepository.insertOnDuplicateKey(relationship);
        if(debug){
            log.debug("绑定手机成功. relationship=[{}]",LogObjects.toString(relationship));
        }
        log.info("创建用户并绑定手机号. userId=[{}],openId=[{}],mobile=[{}]",user.getId(),user.getOpenId(),mobile); // 如果考虑安全,手机号记得脱敏
    }catch(DuplicateKeyException e){
        log.info("创建用户并绑定手机号失败,已存在相同的用户. openId=[{}],mobile=[{}]",user.getOpenId(),mobile);
        throw new CreateConflictException("创建用户发生冲突, openid=[%s]",user.getOpenId());
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29

# 日志错误集锦

back

SLF4J: Failed to load class “org.slf4j.impl.StaticLoggerBinder”.
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
1
2
3

增加jar包,修改pom文件

<!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-simple -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-simple</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-nop -->
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-nop</artifactId>
    <version>${slf4j.version}</version>
    <scope>test</scope>
</dependency>
1
2
3
4
5
6
7
8
9
10
11
12
13