目录
6.1、Log4j、slf4j对象的声明和初始化,仅以下代码是符合规范的
在开发后端接口,服务搭建时,对于日志记录,不仅要有,还要做好,刚好项目团队对于这块疏于管理,对问题排查带来极大困扰,又是老项目,只能用用log4j,简单的记录下日志,减少后期运维工作量,借次,记录log4j用法规范,用于内部参考
- 日志的作用是让方便后期运维,快速定位问题,或监控系统等
- 日志输出,有序有理且不杂乱,有规范
- 业务流程关键环节日志记录,方便排查设计逻辑上的不合理之处
- 下文示例,涉及到参数格式化的地方,无特殊说明,都是用的slf4j,log4j参数格式化
目前的日志存储,一般分为两种:
本地日志:存储在应用服务容器下,指定路径
远程日志:elk loki日志管理平台
Log4j:不支持参数格式化
SLF4J:SLF4J提供了一个名为参数化日志的高级特性,可以显著提高在配置为关闭日志的情况下的日志语句性能
- //slf4j
- log.debug("Found {} records matching filter: '{}'", records, filter);
-
- //log4j
- log.debug("Found " + records + " records matching filter: '" + filter + "'");
可以看出SLF4J的方式一方面更简略易读,另一方面少了字符串拼接的开销,并且在日志级别达不到时(这里例子即为设置级别为debug以上),不会调用对象的toString方法。
ERROR:系统中发生了非常严重的问题,必须马上有人进行处理。没有系统可以忍受这个级别的问题的存在。比如:NPEs(空指针异常),数据库不可用,关键业务流程中断等等
WARN:发生这个级别问题时,处理过程可以继续,但必须对这个问题给予额外关注。这个问题又可以细分成两种情况:一种是存在严重的问题但有应急措施(比如数据库不可用,使用Cache);第二种是潜在问题及建议(ATTENTION),比如生产环境的应用运行在Development模式下、管理控制台没有密码保护等。系统可以允许这种错误的存在,但必须及时做跟踪检查
INFO:重要的业务处理已经结束。在实际环境中,系统管理员或者高级用户要能理解INFO输出的信息并能很快的了解应用正在做什么。比如,一个和处理机票预订的系统,对每一张票要有且只有一条INFO信息描述 "[Who] booked ticket from [Where] to [Where]"。另外一种对INFO信息的定义是:记录显著改变应用状态的每一个action,比如:数据库更新、外部系统请求
DEBUG:用于开发人员使用。将在TRACE章节中一起说明这个级别该输出什么信息
TRACE:非常具体的信息,只能用于开发调试使用。部署到生产环境后,这个级别的信息只能保持很短的时间。这些信息只能临时存在,并将最终被关闭。要区分DEBUG和TRACE会比较困难,对一个在开发及测试完成后将被删除的LOG输出,可能会比较适合定义为TRACE级别
常用log4j配置,一般可以采用两种方式,.properties和.xml,下边以.properties为例:
- #Log4j建议使用四个级别。优先级从高到底error、warn、info、debug
- ### 配置根Logger ###
- log4j.rootLogger=INFO,C,I,D,E
-
- ###控制台(console)###
- ### 输出的四种形式: ###
- #org.apache.log4j.ConsoleAppender(控制台)
- #org.apache.log4j.FileAppender(文件)
- #org.apache.log4j.DailyRollingFileAppender(每天产生一个日志文件)
- #org.apache.log4j.RollingFileAppender(文件大小到达指定尺寸的时候产生一个新的文件)
- log4j.appender.C=org.apache.log4j.ConsoleAppender
- ### 用流的方式输出
- log4j.appender.C.Target=System.out
- ###日志布局
- log4j.appender.C.layout=org.apache.log4j.PatternLayout
- # %L 输出代码中的行号
- # %l 输出日志事件的发生位置,包括类目名、发生的线程,以及在代码中的行数
- # 如:Testlog.main(TestLog.java:10)
- # %m 输出代码中指定的消息
- # %p 输出优先级,即DEBUG,INFO,WARN,ERROR,FATAL
- # %c 输出所属的类目,通常就是所在类的全名
- # %t 输出产生该日志事件的线程名
- # %n 输出一个回车换行符,Windows平台为“\r\n”,Unix平台为“\n”
- # %d 输出日志时间点的日期或时间,默认格式为ISO8601,也可以在其后指定格式
- # 如:%d{yyyy年MM月dd日 HH:mm:ss,SSS},输出类似:2012年01月05日 22:10:28,921
- log4j.appender.C.layout.ConversionPattern=%d{yyyy-MM-dd HH\:mm\:ss,SSS} %-5p(%10c{1}) [%L] %m%n
-
-
- ###定期回滚日志文件(dailyFile)###
- ### 输出DEBUG级别以上的日志文件设置 ###
- log4j.appender.D = org.apache.log4j.DailyRollingFileAppender
- ###日志文件的路径
- log4j.appender.D.File = ${catalina.home}/logs/axis/axis_debug.log
- ###日志是否追加
- log4j.appender.D.Append = true
- ##它的作用是输出DEBUG级别以上的内容到${catalina.home}/logs/axis/中,所以info.log文件中包含了ERROR级别的文件
- log4j.appender.D.Threshold = DEBUG
- log4j.appender.D.DatePattern='.'yyyy-MM-dd
- log4j.appender.D.layout = org.apache.log4j.PatternLayout
- log4j.appender.D.layout.ConversionPattern =%-5p-[%d{yyyy-MM-dd HH\:mm\:ss,SSS}] \: %m%n
-
- ### 输出INFO级别以上的日志文件设置 ###
- log4j.appender.I=org.apache.log4j.DailyRollingFileAppender
- log4j.appender.I.Append=true
- log4j.appender.I.Threshold=INFO
- log4j.appender.I.File=${catalina.home}/logs/axis/axis_info.log
- log4j.appender.I.DatePattern='.'yyyy-MM-dd
- log4j.appender.I.layout=org.apache.log4j.PatternLayout
- log4j.appender.I.layout.ConversionPattern=%-5p-[%d{yyyy-MM-dd HH\:mm\:ss,SSS}] \: %m%n
-
- ### 输出DEBUG级别以上的日志文件设置 ###
- log4j.appender.D = org.apache.log4j.DailyRollingFileAppender
- log4j.appender.D.File = ${catalina.home}/logs/axis/axis_warn.log
- log4j.appender.D.Append = true
- log4j.appender.D.Threshold = WARN
- log4j.appender.D.DatePattern='.'yyyy-MM-dd
- log4j.appender.D.layout = org.apache.log4j.PatternLayout
- log4j.appender.D.layout.ConversionPattern =%-5p-[%d{yyyy-MM-dd HH\:mm\:ss,SSS}] \: %m%n
-
- ### 输出ERROR 级别以上的日志文件设置 ###
- log4j.appender.E = org.apache.log4j.DailyRollingFileAppender
- log4j.appender.E.File = ${catalina.home}/logs/axis/axis_error.log
- log4j.appender.E.Append = true
- log4j.appender.E.Threshold = ERROR
- log4j.appender.E.DatePattern='.'yyyy-MM-dd
- log4j.appender.E.layout = org.apache.log4j.PatternLayout
- log4j.appender.E.layout.ConversionPattern =%-5p-[%d{yyyy-MM-dd HH\:mm\:ss,SSS}] \: %m%n
-
-
-
- ### 输出到数据库 ###
- #(指定输出到数据库)
- log4j.appender.DATABASE=org.apache.log4j.jdbc.JDBCAppender
- #(指定数据库URL)
- log4j.appender.DATABASE.URL=jdbc:mysql://localhost:3306/test
- #(指定数据库driver)
- log4j.appender.DATABASE.driver=com.mysql.jdbc.Driver
- #(指定数据库用户)
- log4j.appender.DATABASE.user=root
- #(指定数据库用户密码)
- log4j.appender.DATABASE.password=123456
- #(组织SQL语句)
- log4j.appender.DATABASE.sql=INSERT INTO LOG4J (Message) VALUES ('[framework] %d - %c -%-4r [%t] %-5p %c %x - %m%n')
- #(布局)
- log4j.appender.DATABASE.layout=org.apache.log4j.PatternLayout
- #(格式)
- log4j.appender.DATABASE.layout.ConversionPattern=[framework] %d - %c -%-4r [%t] %-5p %c %x - %m%n
除此之外,还支持输出到socket,邮件,数据库等
- log4j:
- import org.apache.log4j.Logger;
-
- public class Test {
-
- private static final Logger log = Logger.getLogger(Test.class);
-
- private static final Logger log = Logger.getLogger(this.getClass());
-
- private static final Logger LOGGER = LogManager.getLogger(Test.class);
- }
-
- slf4j:
-
-
- import org.slf4j.Logger;
- import org.slf4j.LoggerFactory;
-
- public class Test {
- private static final Logger logger = LoggerFactory.getLogger(Test.class);
- }
log4j可以使用MessageFormat.format实现参数格式化,或结合slf4j实现参数格式化,如下:
- service.test("1001", "操作站点", "操作人");
- public void test(String opStation, String operCode, String operName) {
- log.info(MessageFormat.format("opStation={0},operCode={1},operName={2}", opStation, operCode, operName));
- }
运行效果:
2021-05-08 09:26:50,362 INFO (NetSaleService) [95] opStation=1001,operCode=操作站点,operName=操作人
log4j这些传统的日志系统里面并没有占位符的概念,当我们需要打印信息的时候,我们就不得不创建无用String对象来进行输出信息的拼接。
slf4j:
slf4j可以使用占位符,这样日志输出的时候就可以避免无用字符串对象的创建
logger.info("Test opStation:[{}] and operCode : [{}] ", opStation, operCode);
对于debug日志,必须判断是否为debug级别后,才进行使用:
- if (logger.isDebugEnabled()) {
- logger.debug("Test opStation:[{}] and operCode : [{}] ", opStation, operCode);
- }
不要进行字符串拼接,那样会产生很多String对象,占用空间,影响性能。反例(不要这么做):
logger.debug("Test opStation: " + opStation+ " operCode: " + operCode);
使用[]进行参数变量隔离,如有参数变量,应该写成如下写法:
logger.debug("Test opStation:[{}] and operCode : [{}] ", opStation, operCode));
这样的格式写法,可读性更好,对于排查问题更有帮助。
- 不得使用System.out, System.err进行日志记录
- 正确的记录异常信息
记录异常信息是“记录所有信息”中的一个重要组成,但很多开发人员只是把logging当做处理异常的一种方式。他们通常返回缺省值,然后当做什么都没发生。 其他时候,他们先log异常信息,然后再抛出包装过的异常。如:
- log.error("IO exception", e);
-
- throw new MyCustomException(e);
这种方法总是会打印两次相同的 stack trace信息,因为有些地方会捕捉MyCustomException异常,然后输出导致问题的日志信息。
但有时基于某些原因我们真的想log异常信息怎么办?很过见多的log语句有一半以上都是错的,
以log4j为例,如:
- try {
- Integer x = null;
- ++x;
- } catch (Exception e) {
-
- // A
- LOGGER.error(e);
-
- // B
- LOGGER.error(e, e);
-
- // C
- LOGGER.error("" + e);
-
- // D
- LOGGER.error(e.toString());
-
- // E
- LOGGER.error(e.getMessage());
-
- // F
- LOGGER.error(null, e);
-
- // G
- LOGGER.error("", e);
-
- // H
- LOGGER.error("{}", e);
-
- // J
- LOGGER.error("Error reading configuration file: " + e);
-
- // K
- LOGGER.error("Error reading configuration file: " + e.getMessage());
-
- // L
- LOGGER.error("Error reading configuration file", e);
-
- }
上面只有G、L是对的,L的处理方式更好一些
- package com.netSale.test;
- import org.apache.log4j.LogManager;
- import org.apache.log4j.Logger;
-
- public class TestLogError {
-
- public static final Logger LOGGER = LogManager.getLogger(TestLogError.class);
-
- public static void main(String[] args) {
-
- try {
-
- // 模拟空指针异常
-
- // Integer nullInt = Integer.valueOf(null);
-
- int[] array = { 1, 2, 3, 4, 5 };
-
- int outBoundInt = array[5];
-
- } catch (Exception e) {
-
- // 直接打印,则只输出异常类型
-
- LOGGER.error(e);
-
- // 使用字符串拼接
-
- LOGGER.error("使用 + 号连接直接输出 e : " + e);
-
- LOGGER.error("使用 + 号连接直接输出 e.getMessage() : " + e.getMessage());
-
- LOGGER.error("使用 + 号连接直接输出 e.toString() : " + e.toString());
-
- // 使用逗号分隔,调用两个参数的error方法
-
- LOGGER.error("使用 , 号 使第二个参数作为Throwable : ", e);
-
- // 尝试使用分隔符,第二个参数为Throwable,会发现分隔符没有起作用,第二个参数的不同据,调用不同的重载方法
-
- LOGGER.error("第二个参数为Throwable,使用分隔符打印 {} : ", e);
-
- }
-
- }
-
- }
运行效果:

使用Logger.error(e)、Logger.error(e.getMessage())、Logger.error("some msg" + e)、Logger.error("some msg" + e.getMessage()) 都是调用的error(Object message),这个方法都会将入参当作Object输出,不会打印堆栈信息。
在使用Logger.error("first param ",e)时会调用error(String message, Throwable t),此方法会完整的打印出错误堆栈信息
注意:捕获异常后不处理也不输出log是一种非常不负责任的行为,这会造成问题很难被定位,极大地提高debug成本!
1)Log的内容一定要确保不会因为Log语句的问题而抛出异常造成中断
log.debug("Processing request with id: {}", request.getId());
你能确保request对象不是NULL吗?如果request为null,就会抛出NullPointerException。
2)避免拖慢应用系统
输出太多日志信息:通常每小时输出到disk的数据量达到几百MiB就已经是上限了不正确使用toString() 或字符串拼接方法。
- try {
- log.trace("Id=" + request.getUser().getId() + " accesses" + manager.getPage().getUrl().toString())
- } catch(NullPointerException e) {
- }
3)日志信息中尽量包含数据和描述
日志信息中尽量包含数据和描述easy to read, easy to parse
一些反模式的例子:
- log.debug("Message processed");
-
- log.debug(message.getJMSMessageID());
-
- log.debug("Message with id '{}' processed", message.getJMSMessageID());
-
- if (message instanceof TextMessage){
-
- //...
- }else {
- log.warn("Unknown message type");
- }
为什么不包含 message type, message id, etc,包含个message content很难吗?另一个anti-pattern是magic-log。
有些开发人员为了自己查找信息方便,输出类似“&&&!#”的Log,而不是“Message with XYZ id received”。
最后,Log 不要涉及密码及个人信息(身份证、银行卡号etc)
5)关键业务系统日志的要求
用户浏览日志
使用WEB服务器或应用服务器实现日志输出,关键信息包括:访问时间、用户IP、访问的URL、用户浏览器信息、HTTP状态码、请求处理时间用户登录日志
用于记录用户的Login、Logout、CheckLogin请求情况,关键信息如下:Login:请求时间、用户IP、用户名、渠道信息、用户浏览器信息、登录处理结果、请求花费时间、tokenId、sessionidLogout:请求时间、用户IP、用户名、渠道信息、用户浏览器信息、登出结果、请求花费时间、tokenid、sessionidCheckLogin:请求时间、用户IP、用户名、渠道信息、用户浏览器信息、检查结果、检查花费时间、tokenid、sessionId服务接口调用日志
所有外部接口的调用需要记录接口访问信息,关键信息如下:
请求时间、接口URL、接口方法、调用结果、执行时间
6)配置规范
统一使用log4j.xml、log4j2.xml、logback配置。
所有的jar包中不推荐包含log4j.xml、log4j.properties、logback.xml文件,避免干扰实际的业务系统。
注意Logger间的继承关系,如:
- log4j的继承是通过命名来实现的。
- 子logger会默认继承父logger的appender,将它们加入到自己的Appender中;除非加上了additivity="false",则不再继承父logger的appender。
- 子logger只在自己未定义输出级别的情况下,才会继承父logger的输出级别。
Log文件位置和命名,目前Log文件的位置统一放在相同目录下面,Log名字通常以业务名开头,如xxx.log.2015-11-19等。
日志格式:必选打印数据项: 发生时间、日志级别、日志内容,可选文件和行号。
远程日志的输出需要注意host和port,区分cagegory。
影响到程序正常运行、当前请求正常运行的异常情况:
log.error("获取用户[{}]的用户信息时出错",userName,e);
反例(不要这么做):
- 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);
- }
基本概念
不应该出现但是不影响程序、当前请求正常运行的异常情况:
即将接近临界值的时候,例如:
基本概念
系统运行信息
外部接口部分
说明
- 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);
- }
基本概念
说明
示例:
- 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);
基本概念
特别详细的系统运行完成信息,业务代码中,不要使用.(除非有特殊用意,否则请使用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());
- }
- }
参考链接
https://www.jianshu.com/p/f42730a2a91d
https://www.jianshu.com/p/8551fe9c6354