Java日志记录最佳实践

2020-08-05 11:32:30 浏览数 (1)

参考：Java日志记录最佳实践

日志框架（HOW）

常用的日志框架

log4j、Logging、commons-logging、slf4j、logback，开发的同学对这几个日志相关的技术不陌生吧，为什么有这么多日志技术，它们都是什么区别和联系呢？且看下文分解：

Logging

这是 Java 自带的日志工具类，在 JDK 1.5 开始就已经有了，在 java.util.logging 包下。通常情况下，这个基本没什么人用了，了解一下就行。

commons-logging

commons-logging 是日志的门面接口，它也是Apache 最早提供的日志门面接口，用户可以根据喜好选择不同的日志实现框架，而不必改动日志定义，这就是日志门面的好处，符合面对接口抽象编程。现在已经不太流行了，了解一下就行。

Slf4j

slf4j,英文全称为“Simple Logging Facade for Java”，为java提供的简单日志Facade。Facade门面，更底层一点说就是接口。它允许用户以自己的喜好，在工程中通过slf4j接入不同的日志系统。

因此slf4j入口就是众多接口的集合，它不负责具体的日志实现，只在编译时负责寻找合适的日志系统进行绑定。具体有哪些接口，全部都定义在slf4j-api中。查看slf4j-api源码就可以发现，里面除了public final class LoggerFactory类之外，都是接口定义。因此slf4j-api本质就是一个接口定义。

Log4j

注意：log4j 在 2015.08.05 这一天被 Apache 宣布停止维护了，用户需要切换到 Log4j2上面去。 Log4j 是 Apache 的一个开源日志框架，也是市场占有率最多的一个框架。

Log4j2

Log4j 2 Apache Log4j 2是apache开发的一款Log4j的升级产品。

Log4j2与Log4j1发生了很大的变化，log4j2不兼容log4j1。

Logback

Logback 是 Slf4j 的原生实现框架，同样也是出自 Log4j 一个人之手，但拥有比 log4j 更多的优点、特性和更做强的性能，现在基本都用来代替 log4j 成为主流。

Logback相对于log4j拥有更快的执行速度。基于我们先前在log4j上的工作，logback 重写了内部的实现，在某些特定的场景上面，甚至可以比之前的速度快上10倍。在保证logback的组件更加快速的同时，同时所需的内存更加少。

日志框架怎么选

选项太多了的后果就是选择困难症，我的看法是没有最好的，只有最合适的：

  • commons-loggin、slf4j 只是一种日志抽象门面，不是具体的日志框架。log4j、logback 是具体的日志实现框架。
  • 在比较关注性能的地方，选择Logback或自己实现高性能Logging API可能更合适。推荐：slf4j logback。
  • 在已经使用了Log4j的项目中，如果没有发现问题，继续使用可能是更合适的方式：推荐组合为：slf4j log4j2。
  • 如果不想有依赖则使用java.util.logging或框架容器已经提供的日志接口。

记录日志的时机

在看线上日志的时候，我们可曾陷入到日志泥潭？该出现的日志没有，无用的日志一大堆，或者需要的信息分散在各个角落，特别是遇到紧急的在线bug时，有效的日志被大量无意义的日志信息淹没，焦急且无奈地浪费大量精力查询日志。那什么是记录日志的合适时机呢？

  • 总结几个需要写日志的点：
  1. 编程语言提示异常：如今各类主流的编程语言都包括异常机制，业务相关的流行框架有完整的异常模块。这类捕获的异常是系统告知开发人员需要加以关注的，是质量非常高的报错。应当适当记录日志，根据实际结合业务的情况使用warn或者error级别。
  2. 业务流程预期不符：除开平台以及编程语言异常之外，项目代码中结果与期望不符时也是日志场景之一，简单来说所有流程分支都可以加入考虑。取决于开发人员判断能否容忍情形发生。常见的合适场景包括外部参数不正确，数据处理问题导致返回码不在合理范围内等等。
  3. 系统核心角色，组件关键动作：系统中核心角色触发的业务动作是需要多加关注的，是衡量系统正常运行的重要指标，建议记录INFO级别日志，比如电商系统用户从登录到下单的整个流程；微服务各服务节点交互；核心数据表增删改；核心组件运行等等，如果日志频度高或者打印量特别大，可以提炼关键点INFO记录，其余酌情考虑DEBUG级别。
  4. 系统初始化：系统或者服务的启动参数。核心模块或者组件初始化过程中往往依赖一些关键配置，根据参数不同会提供不一样的服务。务必在这里记录INFO日志，打印出参数以及启动完成态服务表述。
  • 什么时候应该打日志
  1. 当你遇到问题的时候，只能通过debug功能来确定问题，你应该考虑打日志，良好的系统，是可以通过日志进行问题定为的。
  2. 当你碰到if…else 或者 switch这样的分支时，要在分支的首行打印日志，用来确定进入了哪个分支
  3. 经常以功能为核心进行开发，你应该在提交代码前，可以确定通过日志可以看到整个流程

日志打印最佳实践

日志变量定义

日志变量往往不变，最好定义成 final static，变量名用大写。

代码语言：javascript复制
private static final Logger log = LoggerFactory.getLogger({SimpleClassName}.getClass());

通常一个类只有一个 log 对象，如果有父类可以将 log 定义在父类中。

日志变量类型定义为门面接口（如 slf4j 的 Logger），实现类可以是 Log4j、Logback 等日志实现框架，不要把实现类定义为变量类型，否则日志切换不方便，也不符合抽象编程思想。

参数占位格式

使用参数化形式 {} 占位， [] 进行参数隔离

代码语言：javascript复制
log.debug("Save order with order no：[{}], and order amount：[{}]");

这种可读性好，这样一看就知道[]里面是输出的动态参数，{}用来占位类似绑定变量，而且只有真正准备打印的时候才会处理参数，方便定位问题。

如果日志框架不支持参数化形式，且日志输出时不支持该日志级别时会导致对象冗余创建，浪费内存，此时就需要使用 isXXEnabled 判断，如：

代码语言：javascript复制
if(log.isDebugEnabled()){
    // 如果日志不支持参数化形式，debug又没开启，那字符串拼接就是无用的代码拼接，影响系统性能
    log.debug("Save order with order no："   orderNo   ", and order amount："   orderAmount);
}

至少 debug 级别是需要开启判断的，线上日志级别至少应该是 info 以上的。

日志的基本格式

日志输出主要在文件中，应包括以下内容：

  • 日志时间
  • 日志级别主要使用
  • 调用链标识（可选）
  • 线程名称
  • 日志记录器名称
  • 日志内容
  • 异常堆栈（不一定有）
代码语言：javascript复制
11:44:44.827 WARN [93ef3E0120160803114444] [main] [ClassPathXmlApplicationContext] Exception encountered during context initialization - cancelling refresh attempt

日志时间

作为日志产生的日期和时间，这个数据非常重要，一般精确到毫秒。由于线上一般配置为按天滚动日志文件，日期标识在文件名上，所以可以不放在这个时间中，使用 HH:mm:ss.SSS 格式即可。非要加上也未尝不可，格式推荐：yyyy-MM-dd HH:mm:ss.SSS。

日志级别

主要使用如下的四个级别：

  • DEBUG：DEUBG 级别的主要输出调试性质的内容，该级别日志主要用于在开发、测试阶段输出。该级别的日志应尽可能地详尽，开发人员可以将各类详细信息记录到DEBUG里，起到调试的作用，包括参数信息，调试细节信息，返回值信息等等，便于在开发、测试阶段出现问题或者异常时，对其进行分析。
  • INFO：INFO日志主要记录系统关键信息，旨在保留系统正常工作期间关键运行指标，开发人员可以将初始化系统配置、业务状态变化信息，或者用户业务流程中的核心处理记录到INFO日志中，方便日常运维工作以及错误回溯时上下文场景复现。建议在项目完成后，在测试环境将日志级别调成 INFO，然后通过 INFO 级别的信息看看是否能了解这个应用的运用情况，如果出现问题后是否这些日志能否提供有用的排查问题的信息。
  • WARN：WARN 级别的主要输出警告性质的内容，这些内容是可以预知且是有规划的，比如，某个方法入参为空或者该参数的值不满足运行该方法的条件时。在 WARN 级别的时应输出较为详尽的信息，以便于事后对日志进行分析
  • ERROR：ERROR 级别主要针对于一些不可预知的信息，诸如：错误、异常等，比如，在 catch 块中抓获的网络通信、数据库连接等异常，若异常对系统的整个流程影响不大，可以使用 WARN 级别日志输出。在输出 ERROR 级别的日志时，尽量多地输出方法入参数、方法执行过程中产生的对象等数据，在带有错误、异常对象的数据时，需要将该对象一并输出

问题定位：

  • 发生了什么问题，哪些功能受到影响
  • 获取帮助信息：直接帮助信息或帮助信息的存储位置
  • 通过报警知道解决方案或者找何人解决
代码语言：javascript复制
log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [Probably need to do] [params] .”);
log.error(“[接口名或操作名] [Some Error Msg] happens. [Probably Because]. [please contact xxx@xxx] [params] .”);

调用链标识

在分布式应用中，用户的一个请求会调用若干个服务完成，这些服务可能还是嵌套调用的，因此完成一个请求的日志并不在一个应用的日志文件，而是分散在不同服务器上不同应用节点的日志文件中。该标识是为了串联一个请求在整个系统中的调用日志。

调用链标识格式：

  • 唯一字符串（trace ID）
  • 调用层级（span ID）

调用链标识作为可选项，无该数据时只输出 [] 即可。

线程名称

输出该日志的线程名称，一般在一个应用中一个同步请求由同一线程完成，输出线程名称可以在各个请求产生的日志中进行分类，便于分清当前请求上下文的日志。

日志记录器名称

日志记录器名称一般使用类名，日志文件中可以输出简单的类名即可，看实际情况是否需要使用包名和行号等信息。主要用于看到日志后到哪个类中去找这个日志输出，便于定位问题所在。

日志内容

  • 禁用 System.out.println和System.err.println
  • 变参替换日志拼接
  • 输出日志的对象，应在其类中实现快速的 toString 方法，以便于在日志输出时仅输出这个对象类名和 hashCode
  • 预防空指针:不要在日志中调用对象的方法获取值，除非确保该对象肯定不为 null，否则很有可能会因为日志的问题而导致应用产生空指针异常。
代码语言：javascript复制
// 不推荐
log.debug( "Load student(id={}), name: {}" , id , student.getName() );

// 推荐
log.debug( "Load student(id={}), student: {}" , id , student );

对于一些一定需要进行拼接字符串，或者需要耗费时间、浪费内存才能产生的日志内容作为日志输出时，应使用 log.isXxxxxEnable() 进行判断后再进行拼接处理，比如：

代码语言：javascript复制
if (log.isDebugEnable()) {
    StringBuilder builder = new StringBuilder();
    for (Student student : students) {
        builder.append("student: ").append(student);
    }
    builder.append("value: ").append(JSON.toJSONString(object));
    log.debug( "debug log example, detail: {}" , builder );
}

异常堆栈

异常堆栈一般会出现在 ERROR 或者 WARN 级别的日志中，异常堆栈含有方法调用链的系统，以及异常产生的根源。异常堆栈的日志属于上一行日志的，在日志收集时需要将其划至上一行中。

日志文件

日志文件放置于固定的目录中，按照一定的模板进行命名，推荐的日志文件名称：

代码语言：javascript复制
当前正在写入的日志文件名：<应用名>[-<功能名>].log
已经滚入历史的日志文件名：<应用名>[-<功能名>].log.<yyyy-MM-dd>

日志配置

根据不同的环境配置不同的日志输出方式：

  • 本地调试可以将日志输出到控制台上
  • 测试环境或者生产环境输出到文件中，每天产生一个文件，如果日志量庞大可以每个小时产生一个日志文件
  • 生产环境中的文件输出，可以考虑使用异步文件输出，该种方式日志并不会马上刷新到文件中去，会产生日志延时，在停止应用时可能会导致一些还在内存中的日志未能及时刷新到文件中去而产生丢失，如果对于应用的要求并不是非常高的话，可暂不考虑异步日志

logback 日志工具可以在日志文件滚动后将前一文件进行压缩，以减少磁盘空间占用，若使用 logback 对于日志量庞大的应用建议开启该功能。

具体的配置示例，由于篇幅较长，单独开一篇介绍。详情可移步：日志使用项目实战

日志使用规范

  • 在一个对象中通常只使用一个Logger对象，Logger应该是static final的，只有在少数需要在构造函数中传递logger的情况下才使用private final。 private static final Logger log = LoggerFactory.getLogger(Main.class);
  • 不要使用具体的日志实现类 InterfaceImpl interface = new InterfaceImpl(); 这段代码大家都看得懂吧？应该面向接口的对象编程，而不是面向实现，这也是软件设计模式的原则，正确的做法应该是。
代码语言：javascript复制
Interface interface = new InterfaceImpl();

日志框架里面也是如此，上面也说了，日志有门面接口，有具体实现的实现框架，所以大家不要面向实现编程。

  • 输出Exceptions的全部Throwable信息。因为log.error(msg)和log.error(msg,e.getMessage())这样的日志输出方法会丢失掉最重要的StackTrace信息。 void foo(){ try{ //do somehing }catch(Exception e){ log.error(e.getMessage());//错误示范 log.erroe("Bad Things",e.getMessage());//错误示范 log.error("Bad Things",e);//正确演示 } }
  • 不允许记录日志后又抛出异常。如捕获异常后又抛出了自定义业务异常，此时无需记录错误日志，由最终捕获方进行异常处理。不能又抛出异常，又打印错误日志，不然会造成重复输出日志。 void foo() throws LogException{ try{ //do somehing }catch(Exception e){ log.error("Bad Things",e);//正确 throw new LogException("Bad Things",e); } }
  • 不允许使用标准输出 包括System.out.println()和System.error.println()语句。因为这个只会打印到控制台，而不会记录到日志文件中，不方便管理日志。此外，标准输出不会显示类名和行号信息，一旦代码中大量出现标准输出的代码，且日志中打印有标准输出的内容，很难定位日志内容和日志打印的位置，根本无法排查问题，想删除无用日志输出也改不动，这个是笔者在重构古董代码的时候亲自踩过的一个坑。 void foo(){ try{ //do somehing }catch(Exception e){ Syste.out.println(e.getMessage());//错误 System.error.println(e.getMessage());//错误 log.error("Bad Things",e);//正确 } }
  • 不允许出现printStackTrace void foo(){ try{ //do somehing }catch(Exception e){ e.printStacktrace();//错误 log.error("Bad Things",e);//正确 } }

来看一下它的源码：

代码语言：javascript复制
public void printStackTrace() {
    printStackTrace(System.err);
}

它其实也是利用 System.err 输出到了Tomcat控制台。

  • 禁止在线上环境开启debug级别日志输出 出于日志性能的考虑，如果代码为核心代码，执行频率非常高，则输出日志建议增加判断，尤其是低级别的输出<debug、info、warn>。

一是因为项目本身 debug 日志太多，二是各种框架中也大量使用 debug 的日志，线上开启 debug 不久就会打满磁盘，影响业务系统的正常运行。

  • 不要在大循环中打印日志 如果你的框架使用了性能不高的 Log4j 框架，那就不要在上千个 for 循环中打印日志，这样可能会拖垮你的应用程序，如果你的程序响应时间变慢，那要考虑是不是日志打印的过多了。
代码语言：javascript复制
for(int i=0; i<2000; i  ){
    log.info("XX");
}

最好的办法是在循环中记录要点，在循环外面总结打印出来。

  • 打印有意义的日志 通常情况下在程序日志里记录一些比较有意义的状态数据：程序启动，退出的时间点；程序运行消耗时间；耗时程序的执行进度；重要变量的状态变化。

规范示例说明

代码语言：javascript复制
@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());
    }
}

信息安全

切记不要 log 密码及个人信息相关的内容！为了便于进行问题定位，以下是涉及敏感信息日志输出时最为宽松（明文显示的数据只能更少，不能更多）的要求：

类型

要求

示例

说明

密码

不输出

******

登录密码、支付密码等各种类型的密码

信用卡 CVV2

不输出

***

信用卡有效期

不输出

****

验证码

不输出

******

图形验证码、短信验证码、邮件验证码等

密钥、盐

不输出

******

用于加解密算法的密钥，消息摘要的盐，以及数字签名及签名验证算法所使用的公私钥对等

会话 ID设备指纹 (ID)指纹 token密文数据

前 5 后 5

***

主要有以下类型：1. 应用的会话标识，比如：Web、APP、H5 等用于识别会话状态信息的标识2. APP 标识设备的设备指纹或者设备 ID3. APP 用于指纹验证的 token4. 密文数据指的是加密后的数据被掩码的字符无论多少位都输出 3 个 *

银行卡卡号

前 6 后 4

622666**0831

银行卡卡号最多 19 位数字

手机号

前 3 后 4

137****9574

定长 11 位数字

身份证号

前 1 后 1

3**X

定长 18 位数字

姓名

隐姓

*世仁

将姓氏隐藏

IP 地址

前 1 后 1

10...27

隐藏 IP 地址的第 2、第 3 段

邮箱地址

前 1 后 1

w**3@gmail.com

仅对 @ 之前的邮箱名称进行掩码，掩码部分不管多少位均输出 ***

地址

隐号码

上海市西藏北路 *** 号 *** 楼 *** 室

上述仅列取出部分数据的显示要求，其他的显示原则为通过掩码后的数据无法得知原始数据。

实现了如上掩码的工具类，参考：https://github.com/frankiegao123/mask-utils

javascript 日志服务 tcp/ip

0 人点赞