1.java程序员必知必会类库之日志

文章列表

1.java程序员必知必会类库之日志

日志库是很常见的，因为你在每一个项目中都需要他们。打印日志是服务器端应用中最重要的事情，因为日志是你了解你的程序发生了什么的唯一途径。尽管JDK附带自己的日志库，但是还是有很多更好的选择可用。
例如 Log4j 、 SLF4j 和 LogBack。本文基于笔者日志框架的使用经验，以及多家公司的代码规范要求等，做了一些总结和思考，Java开发人员应该熟悉日志记录的利弊，并且了解为什么SLF4J要比Log4J要好。
读者在设计自己公司日志规范的时候，大家可以学习交流一下

为啥slf4j比log4j好

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世界的日志标准。
在代码中表示为{}的特性。占位符是一个非常类似于在String的format()方法中的%s，它会在运行时被某个提供的实际字符串所替换。
这不仅降低了你代码中字符串连接次数，而且还节省了新建的String对象。因为String对象是不可修改的并且它们建立在一个String池中，它们消耗堆内存( heap memory)而且大多数时间他们是不被需要的，例如当你的应用程序在生产环境以ERROR级别运行时候，一个String使用在DEBUG语句就是不被需要的。
通过使用SLF4J,你可以在运行时延迟字符串的建立，这意味着只有需要的String对象才被建立。而如果你已经使用log4j，那么你已经对于在if条件中使用debug语句这种变通方案十分熟悉了，但SLF4J的占位符就比这个好用得多。

原因总结：

在你的开源或内部类库中使用SLF4J会使得它独立于任何一个特定的日志实现，这意味着不需要管理多个日志配置或者多个日志类库，你的客户端会很感激这点。
SLF4J提供了基于占位符的日志方法，这通过去除检查isDebugEnabled(),isInfoEnabled()等等，提高了代码可读性。
通过使用SLF4J的日志方法，你可以延迟构建日志信息（Srting）的开销，直到你真正需要，这对于内存和CPU都是高效的。
作为附注，更少的暂时的字符串意味着垃圾回收器（GarbageCollector）需要做更好的工作，这意味着你的应用程序有为更好的吞吐量和性能。

常用日志框架配置

上文提到我们slf4j只是规范，提供了api，但是具体打印日志，还是需要底层的日志框架和日志框架适配器。当前比较主流的日志框架有log4j 以及 logback,下面分别阐述两个日志框架的使用细节

log4j

pom坐标

<dependency><groupId>org.slf4j</groupId><artifactId>slf4j-api</artifactId><version>1.7.36</version>
</dependency>
<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.29</version>
</dependency>

配置说明

配置根rootLogger : 用于配置当前日志输出的级别以及输出的位置
配置日志信息输出目的地Appender:
log4j.appender.appenderName=位置
log4j.appender.appenderName.optionN = valueN (根据位置不同，对应不同的optionN选项属性)

具体可根据实际需求，选择在rootlogger里面配置哪几个appender。

测试案例如下：

log4j.rootLogger=DEBUG, stdout,systemOut,logFile,logDailyFile,logRollingFile
# 控制台测试1
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] - %m%n#控制台测试2
log4j.appender.systemOut = org.apache.log4j.ConsoleAppender
log4j.appender.systemOut.layout = org.apache.log4j.PatternLayout
log4j.appender.systemOut.layout.ConversionPattern = [%-5p][%-22d{yyyy/MM/dd HH:mm:ssS}][%l]%n%m%n
log4j.appender.systemOut.Threshold = DEBUG
log4j.appender.systemOut.ImmediateFlush = TRUE
log4j.appender.systemOut.Target = System.out#文件
log4j.appender.logFile = org.apache.log4j.FileAppender
log4j.appender.logFile.layout = org.apache.log4j.PatternLayout
log4j.appender.logFile.layout.ConversionPattern = [%-5p][%-22d{yyyy/MM/dd HH:mm:ssS}][%l]%n%m%n
log4j.appender.logFile.Threshold = DEBUG
log4j.appender.logFile.ImmediateFlush = TRUE
log4j.appender.logFile.Append = TRUE
log4j.appender.logFile.File = D://log.log
log4j.appender.logFile.Encoding = UTF-8#按照日期回滚文件
log4j.appender.logDailyFile = org.apache.log4j.DailyRollingFileAppender
log4j.appender.logDailyFile.layout = org.apache.log4j.PatternLayout
log4j.appender.logDailyFile.layout.ConversionPattern = [%-5p][%-22d{yyyy/MM/dd HH:mm:ssS}][%l]%n%m%n
log4j.appender.logDailyFile.Threshold = DEBUG
log4j.appender.logDailyFile.ImmediateFlush = TRUE
log4j.appender.logDailyFile.Append = TRUE
log4j.appender.logDailyFile.File = D://log.log 
log4j.appender.logDailyFile.DatePattern = '.'yyyy-MM-dd-HH-mm'.log'
log4j.appender.logDailyFile.Encoding = UTF-8#按照文件大小切割文件
log4j.appender.logRollingFile = org.apache.log4j.RollingFileAppender
log4j.appender.logRollingFile.layout = org.apache.log4j.PatternLayout
log4j.appender.logRollingFile.layout.ConversionPattern = [%-5p][%-22d{yyyy/MM/dd HH:mm:ssS}][%l]%n%m%n
log4j.appender.logRollingFile.Threshold = DEBUG
log4j.appender.logRollingFile.ImmediateFlush = TRUE
log4j.appender.logRollingFile.Append = TRUE
log4j.appender.logRollingFile.File = D://log.log
log4j.appender.logRollingFile.MaxFileSize = 1MB
log4j.appender.logRollingFile.MaxBackupIndex = 10
log4j.appender.logRollingFile.Encoding = UTF-8

具体配置项说明，详见文末链接文章

注意事项
3.1 注意上面pom，添加日志框架，如果使用slf4j ,需要有对应的日志框架适配器和slf4j 适配，否则会报错

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation

3.2 resource目录下要有文件名为log4j.properties 的配置文件，不然日志打印不出来，报错

log4j:WARN No appenders could be found for logger (Testlog4j).
log4j:WARN Please initialize the log4j system properly.

3.3 一个日志门面只能配置一个日志适配器，如果pom依赖里面添加多个会警告，多个会选择pom里面第一个

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/D:/toolsdata/maven/mavenjar/org/slf4j/slf4j-log4j12/1.7.29/slf4j-log4j12-1.7.29.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/D:/toolsdata/maven/mavenjar/ch/qos/logback/logback-classic/1.2.11/logback-classic-1.2.11.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]

logback

pom坐标

<dependency><groupId>org.slf4j</groupId><artifactId>slf4j-api</artifactId><version>1.7.36</version>
</dependency>
<dependency><groupId>ch.qos.logback</groupId><artifactId>logback-classic</artifactId><version>1.2.11</version>
</dependency>

配置说明
如果没有自己定义logback的配置文件， logback 默认地会调用BasicConfigurator ，创建一个最小化配置。最小化配置由一个关联到根 logger 的ConsoleAppender 组成，调用PatternLayoutEncoder机械能格式化。root logger 默认级别是 DEBUG。

2.1 logback 常用配置如下：

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false"><!--定义日志文件目录和应用名，后续这配置可以放外面，让日志文件配置通用--><property name="logging.app.path" value="/app/logs"/><property name="logging.app.name" value="DEDataService"/><!--定义日志文件的存储地址 勿在 LogBack 的配置中使用相对路径--><property name="LOG_HOME" value="${logging.app.path}/${logging.app.name}"/><!-- 控制台输出 --><appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"><encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"><!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符--><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern></encoder></appender><!-- 按照每天生成日志文件 --><appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"><rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy"><!--日志文件输出的文件名 按天，按照大小切割，压缩--><FileNamePattern>${LOG_HOME}/info.log.%d{yyyy-MM-dd}.%i.log.zip</FileNamePattern><!--日志文件大小--><maxFileSize>100MB</maxFileSize><!--日志文件保留天数--><MaxHistory>30</MaxHistory></rollingPolicy><encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"><!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符--><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern></encoder></appender><appender name="ERRORFILE" class="ch.qos.logback.core.rolling.RollingFileAppender"><rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"><!--日志文件输出的文件名 错误日志因为一般比较少，因此可以不压缩--><FileNamePattern>${LOG_HOME}/error.log.%d{yyyy-MM-dd}.log</FileNamePattern><!--日志文件保留天数--><MaxHistory>30</MaxHistory></rollingPolicy><filter class="ch.qos.logback.classic.filter.LevelFilter"><!--定义了一个过滤器,在LEVEL之下的日志输出不会被打印出来--><level>error</level><!--但是如果添加如下配置，只会打印当前日志等级的日志，其他的不会打印--><onMatch>ACCEPT</onMatch><onMismatch>DENY</onMismatch></filter><encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder"><!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符--><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern></encoder></appender><!--对于类路径以 com.test0 开头的Logger,输出级别设置为warn--><!--这个logger没有指定appender，它会继承root节点中定义的那些appender--><logger name="com.test0" level="warn"/><!--对于类路径以 com.test3 开头的Logger,输出级别设置为off off日志等级最高，即为关闭com.test3开头的日志打印--><logger name="com.test3" level="OFF"/><!--通过 LoggerFactory.getLogger("mytest") 可以获取到这个logger--><!--由于这个logger自动继承了root的appender，root中已经有stdout的appender了，自己这边又引入了stdout的appender--><!--如果没有设置 additivity="false" ,就会导致一条日志在控制台输出两次的情况--><!--additivity表示要不要使用rootLogger配置的appender进行输出--><logger name="com.test1" level="info" additivity="false"><appender-ref ref="STDOUT"/></logger><!--由于设置了 additivity="false" ，所以输出时不会使用rootLogger的appender--><!--但是这个logger本身又没有配置appender，所以使用这个logger输出日志的话就不会输出到任何地方--><logger name="com.test2" level="info" additivity="false"/><!-- 日志输出级别 root是默认的logger 这里设定输出级别是debug --><root level="INFO"><!--定义了三个appender，日志会通过往这三个appender里面写--><appender-ref ref="STDOUT"/><appender-ref ref="FILE"/><appender-ref ref="ERRORFILE"/></root>
</configuration>

将上述配置文件logback.xml 添加到项目resource目录下面，启动项目有如下输出，可以看到我们在配置文件配置的很多细节都有在日志中体现。

19:01:57,685 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
19:01:57,685 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
19:01:57,685 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/D:/code/newcode/DEDataAdapter/target/classes/logback.xml]
19:01:57,693 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath.
19:01:57,693 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [jar:file:/D:/code/newcode/DEDataAdapter/libs/invoice-datamodel-1.0.0.jar!/logback.xml]
19:01:57,693 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/D:/code/newcode/DEDataAdapter/target/classes/logback.xml]
19:01:57,776 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
19:01:57,779 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
19:01:57,782 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
19:01:57,859 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
19:01:57,866 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]
19:01:57,872 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@2056418216 - Archive files will be limited to [100 MB] each.
19:01:57,872 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@2056418216 - Will use zip compression
19:01:57,872 |-INFO in c.q.l.core.rolling.SizeAndTimeBasedRollingPolicy@2056418216 - Will use the pattern /app/logs/DEDataService/info.log.%d{yyyy-MM-dd}.%i.log for the active file
19:01:57,882 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@26a7b76d - The date pattern is 'yyyy-MM-dd' from file name pattern '/app/logs/DEDataService/info.log.%d{yyyy-MM-dd}.%i.log.zip'.
19:01:57,882 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@26a7b76d - Roll-over at midnight.
19:01:57,883 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@26a7b76d - Setting initial period to Wed Apr 12 19:01:57 CST 2023
19:01:57,890 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: /app/logs/DEDataService/info.log.2023-04-12.0.log
19:01:57,890 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [null]
19:01:57,890 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
19:01:57,890 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [ERRORFILE]
19:01:57,892 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1253946629 - No compression will be used
19:01:57,892 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1253946629 - Will use the pattern /app/logs/DEDataService/error.log.%d{yyyy-MM-dd}.log for the active file
19:01:57,894 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern '/app/logs/DEDataService/error.log.%d{yyyy-MM-dd}.log'.
19:01:57,894 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
19:01:57,894 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Wed Apr 12 19:01:57 CST 2023
19:01:57,901 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ERRORFILE] - Active log file name: /app/logs/DEDataService/error.log.2023-04-12.log
19:01:57,901 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[ERRORFILE] - File property is set to [null]
19:01:57,902 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.test0] to WARN
19:01:57,902 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.test3] to OFF
19:01:57,902 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.test1] to INFO
19:01:57,902 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.test1] to false
19:01:57,902 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[com.test1]
19:01:57,903 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.test2] to INFO
19:01:57,903 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [com.test2] to false
19:01:57,903 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO
19:01:57,903 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
19:01:57,903 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [FILE] to Logger[ROOT]
19:01:57,903 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [ERRORFILE] to Logger[ROOT]
19:01:57,903 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
19:01:57,904 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@7ce6a65d - Registering current configuration as safe fallback point

注意事项
3.1 logback 会从很多目录找配置文件xml,笔者之前项目刚开始犯得一个错是，springboot项目打的包里面有配置文件，在jar包外面有配置文件，结果因为jar包外面的yml没指定读取外面的logback.xml，导致项目读的是jar里面，即类路径下的配置

springboot yml增加配置如下：
```
logging:#类路径，本地调试可以使用，不推荐config: classpath:logback-pro.xml#绝对路径，生产和本地调试使用，推荐config: /app/conf/dataservice/logback-pro.xml
```

log级别与log使用规范

log级别

Fatal：指出每个严重的错误事件将会导致应用程序的退出，极少使用一般是启动时必要的内容没有初始化完成
Error：严重业务错误，阻断业务运行。如：查询商品失败。
Warn:表明会出现潜在错误的情形，有些信息不是错误信息，但是也要给程序员的一些提示。业务警告，如：传入参数错误，缺少部分属性主要信息但可以展示
Info: 一般业务信息，打印一些你感兴趣的或者重要的信息，表明用户或程序在做什么，如：加购物车操作,定时任务启动。这个可以用于生产环境中输出程序运行的一些重要信息，但是不能滥用，避免打印过多的日志。
Debug: 主要用于开发过程中打印一些运行信息，调试信息，比如调试接口返回，查询结果等
TRACE： designates finer-grained informational events than the DEBUG.Since:1.2.12，很低的日志级别，一般不会使用。

从上往下，日志级别依次降低，如果将log level设置在某一个级别上，那么比此级别优先级高的log都能打印出来。例如，如果设置优先级为WARN，那么FATAL、ERROR、WARN 3个级别的log能正常输出，而INFO、DEBUG、TRACE级别的log则会被忽略。

log使用规范

初始化：一般情况下使用
private static org.slf4j.Logger log = LoggerFactory.getLogger(xxx.class);
log中可以使用{}占位符来表示要传的参数, Exception要单独跟一个参数不能被解析为占位参数
一般情况下需要记录相关的参数，但业务敏感参数不要记录在log中
记录本方法相关的日志不需要记录方法名，调用其他方法时记录日志需要记录方法名
日志参数中需要调用耗时方法的如：json转换。如果不是error级别需要判断当前级别的日志是否启用。if(logger.isInfoEnabled()){}

Log在公司应用各层中的细节

Action层也叫Controller层

只记录业务（用户xxx登录，用户×××登录失败）日志一般级别是info
异常不单独处理使用Global中统一的拦截器ExceptionControllerAdvice处理异常。

Service层

调用内部servcie：

不需要对service结果记录日志

调用外部Service

使用try catch并判断service返回结果，当返回错误或者有异常时需要抛出RemoteServiceException并log error
log中记录调用远程的方法名，及非敏感参数需要记录在日志中

示例：

   try {output = productClient.callRemoteService(input);} catch (Exception e) {log.error("productClient.callRemoteService异常, inputDTO={}", JSON.toJSONString(input), e);throw new RemoteServiceException(FrontModule.PRODUCT.getCode(), "查询产品信息异常");}

调用DAO

需要对DAO的预期结果判断，预期没有返回数据的需要记录日志，并抛出业务异常
一个service中调用多个DAO可以抛出相同业务异常类，及消息，用code来区分错误内容，在日志中详细记录调用哪个方法出错。
需要对DAO的异常进行捕捉，记录日志并抛出对DAO层的异常封装。
业务异常（除参数异常外）不需要带参数，因为在log中已经记录了参数。

DAO层

直接抛出底层异常，不用使用try catch
一般不需要特别记录日志

特别规定

禁止使用System.out, System.err
禁止使用e.printStack
log输出以下内容必须打码
3.1 用户名密码（不能输出密码）
3.2 用户校验码
3.3 userToken（可以用userId）
3.4 支付银行卡号（可逆）
3.5 用户身份证（可逆）
3.6 其他敏感信息

参考文献

slf4j优于log4j的原因
log4j详细配置
log4j按照日期加大小切割参考（未验证）
Slf4j日志绑定/日志桥接

1.java程序员必知必会类库之日志

为啥slf4j比log4j好

原因总结：

常用日志框架配置

log4j

logback

log级别与log使用规范

log级别

log使用规范

Log在公司应用各层中的细节

Action层也叫Controller层

Service层

调用内部servcie：

调用外部Service

调用DAO

DAO层

特别规定

参考文献

相关问题

公告