听我的，日志还是得好好打！

539次阅读  |  发布于1年以前

大家好，我是老三，不知道大家有没有经历过这样的场景，线上出了问题，着急火燎地去排查：

唉，问题可能出在这个地方，捞个日志看下，卧槽，怎么找不到……哪个**不打日志，啊，原来是我自己。

日志这东西，平时看不出来什么，真要出了问题，那就是救命的稻草。这期就给大家分享一些日志相关的东西。

弄懂日志

SpringBoot项目启动日志

什么是日志？

日志，维基百科中对其的定义是一个或多个由服务器自动创建和维护的日志文件，其中包含其所执行活动的列表。

作为开发，我们都熟悉日志的重要性，良好的日志，能帮助我们快速定位到错误发生的详情和原因，并快速解决问题。

为什么要打日志？

前面提到日志可以提供精准的系统记录方便根因分析，那为什么要记录日志，记录日志有哪些作用呢？

什么时候打日志？

那么一般会在什么时候打日志呢？下面列举了一些常见的场景：

需要注意的是，日志记录的频率和打印量应根据具体情况进行评估和调整，避免日志过于频繁或过于庞大。

怎么打日志？

大家都知道，Java别的不多，就是轮子多，在Java程序里，打印日志，可以选择的方法和轮子也不少：

  1. System.out.println()：将日志信息打印到标准输出流（控制台），最简单的方式，但是不灵活。
  2. java.util.logging：Java自带的日志框架，提供了一套API用于记录日志，可以控制日志级别和输出目标。
  3. Log4j：流行的开源日志框架，提供了丰富的功能和配置选项，支持异步输出和滚动日志文件等特性。
  4. SLF4J：日志门面框架，提供了统一的API，可以与不同的日志实现进行适配。
  5. Logback：由Log4j的创始人开发的高性能日志框架，可作为SLF4J的实现。

在项目中，一般推荐用SLF4J作为日志门面框架，和不同的日志框架进行适配，如果因为某些原因，比如前两年，Log4j曝出了大漏洞，需要进行替换和升级的时候，只需要修改相应的依赖和配置即可，而不需要修改项目里的日志记录代码。

怎么查日志？

日志打完了就得用，用就得查，那么我们打印的日志怎么查询呢？

日志文件

一般通过日志框架打印日志的时候，都会配置日志输出的路径：

  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>/path/to/logs/myapp.log</file>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

查看日志最简单直接的方法，就是在对应的目录下，去寻找相应的日志，在Linux系统中，可以通过这些命令去查看日志文件：

  1. cat：可以使用cat命令来查看日志文件的内容。

例如，使用cat /var/log/syslog命令可以查看系统日志文件的内容。 2. tail：tail命令可以用来显示文件的末尾内容，常用于实时查看日志文件的更新。

使用tail -f /var/log/syslog命令可以实时查看系统日志文件的更新内容。 3. less：less命令可以用来浏览文件的内容，并且支持向上和向下滚动。

例如，使用less /var/log/syslog命令可以打开系统日志文件，并通过上下箭头键来滚动浏览文件内容。 4. grep：grep命令可以用来在文件中搜索指定的关键字或模式。

例如，使用grep "error" /var/log/syslog命令可以查找系统日志文件中包含"error"关键字的行。

除了命令行工具，还可以使用一些图形化的日志查看工具来浏览和分析日志文件，例如logrotate、journalctl等。

现在的服务，一般都是容器化部署，可以通过容器的日志命令来查看日志：

  1. Docker：如果用的是Docker管理容器，可以使用docker logs命令来查看容器的日志。例如，使用docker logs命令可以查看指定容器的日志内容。
  2. Kubernetes：如果用的是Kubernetes管理容器，可以使用kubectl logs命令来查看容器的日志。例如，使用kubectl logs命令可以查看指定Pod中容器的日志内容。

ELK

直接通过日志文件查询日志可能会比较繁琐，效率比较低，可以使用一些日志聚合工具来收集和管理日志。例如使用使用ELK Stack（Elasticsearch, Logstash, Kibana）来集中管理和可视化日志。

ELK收集日志

Kibana查询日志

SLS

SLS（阿里云日志服务）是由阿里云提供的商业化日志收集解决方案，它提供了一站式的日志数据采集、消费和查询分析功能，无需开发即可使用。

SLS产品功能

通过SLS，可以方便地收集、存储和查询日志数据，进行实时监控、故障排查和业务分析。同时，SLS还提供了丰富的查询和分析功能，如日志关键词搜索、日志分析报表等，整体功能还是非常强大的——毕竟要氪金。

SLS的查询分析界面

更多关于SLS阿里云日志服务的详细信息，大家可以搜索相关文档或访问阿里云官方网站进行了解，这里就不展开更多了。

打印日志最佳实践

打日志这件事情，说起来很简单，有手就行，但是想要打良好的日志，就没那么那么简单。

那么，怎样才算是一份良好的日志呢？应该具备这些特点：

良好日志拼图

  1. 详细和准确：日志应该记录足够详细的信息，包括时间、触发事件、相关参数和上下文等，方便我们快速理解时间的发生和上下文。
  2. 可读性强：日志应该使用易于阅读和理解的格式，日志信息能够被其它开发人员快速理解，而不需要费力解析复杂的日志内容。
  3. 可配置性：日志系统应该具备可配置的选项，以便开发人员可以根据需要调整日志级别、输出目标和格式等。
  4. 性能高效：日志记录应该对系统性能的影响尽可能小，避免对应用程序的正常运行造成明显的延迟。
  5. 安全性：日志应该保护敏感信息的安全性，避免将敏感数据记录在日志中，以防止信息泄露的风险。

那么接下来，围绕这些要点，我们来看看打印日志的最佳实践。

1.选择合适的日志级别

在选择日志级别时，需要根据不同的场景和需求来确定合适的级别。

以下是常见的日志级别及其适用场景：

日志级别

在实际应用中，可以根据具体需求和系统特点，选择合适的日志级别来平衡日志的详细程度和性能开销。通常建议在生产环境中使用较高级别的日志级别（如Error、Warn、Info），而在开发和测试环境中可以使用更详细的级别（如Trace、Debug）来辅助调试和排查问题。

2.选择适当的日志格式

在实际的开发中，可能会打印不同种类的日志，常见的日志种类包括：

常见日志类型日志打印的时候，日志格式要尽量兼顾完备性、可读性和性能。

摘要日志

摘要日志是一种标准化的日志文件，主要用于监控系统配置和进行离线日志分析。它通常包含以下关键信息：

2022-12-12 06:05:05,129 [0b26053315407142451016402xxxxx 0.3 - /// - ] INFO [SofaBizProcessor-4-thread-333] - [(interfaceName,methodName,1ms,Y,SUCCESS)(appName,ip地址,时间戳,Y)

在Java中，通常可以通过配置日志框架来定义一些通用信息的打印，比如调用时间、日志链路id、方法名等。具体的配置方式取决于所选择的日志框架。

例如使用Logback作为日志框架：

<configuration>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{traceId}] [%thread] [%logger{0}] - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="INFO">
    <appender-ref ref="CONSOLE" />
  </root>
</configuration>

详细日志

详细日志是一种补充摘要日志中的业务参数的日志文件，主要用于问题排查。除了包含摘要日志的所有信息，详细日志还会记录请求的入参和出参。

2022-12-12 06:05:05,129 [0b26053315407142451016402xxxxx 0.3 - /// - ] INFO [SofaBizProcessor-4-thread-333] - [(interfaceName,methodName,1ms,Y,SUCCESS)(appName,ip地址,时间戳,Y)(参数1,参数2)(xxxx)

业务执行日志

业务执行日志主要记录系统执行过程，用于跟踪代码执行逻辑。在打印业务执行日志时，需要考虑以下几个因素：

建议的格式是：[日志场景][日志含义]带业务参数的具体信息。这种格式可以清晰地表述出打印该条日志的作用，方便后续维护人员阅读。

[scene_bind_feature][feature_exists]feature xxx exists[tagSource='MIF_TAG',tagValue='123']

3.建议入参出参打印日志

建议在与接口相关的日志以及关键方法的入参和返回值中添加日志，以便更好地追踪和调试代码。

正例：

 public String myMethod(String param1, int param2) {
        logger.info("Entering myMethod. Param1: {}, Param2: {}", param1, param2);

        // 方法逻辑
        String result = "some result";
        logger.info("Exiting myMethod. Result: {}", result);
        return result;

4.使用占位符{}而不是拼接+

使用占位符{}而不是+号进行字符串拼接，更加优雅和高效。使用占位符{}的方式可以提高代码的可读性，并且避免了使用+号进行字符串拼接时可能出现的性能损耗。

反例：

logger.info("Processing trade with id: " + id + " and symbol: " + symbol);

正例：

logger.info("Processing trade with id: {} and symbol : {} ", id, symbol);

5.建议日志要打英文

建议在打印日志时使用英文，因为使用中文，可能会有两个问题：

反例：

logger.info("用户登录成功，用户名：{}","张三");

正例：

logger.info("User login successful. Username:{} ","Zhang San");

6.日志要打印关键参数

日志最重要的作用是用于排查问题和追踪代码执行过程，因此建议在日志中打印关键的公共参数或业务参数，如Trace ID、Order ID等。

正例：

 logger.info("Placing order, Order ID: {}, Customer ID: {}, Amount: {}",  orderId, customerId, amount);
        // 下单逻辑
        String result = "Order placed successfully";
        logger.info("Order placed. Order ID: {}, Result: {}",  orderId, result);

7.建议多分支首行打印日志

在条件分支比较复杂的情况下，建议在进入分支的首行打印相关信息，方便在调试，或者出现问题的时候，知道我们的代码进入的是哪一个分支。

正例：

  public void process(String type) {
        if ("xxx".equals(type)) {
            logger.debug("Current branch type: xxx");
            // Branch xxx logic
        } else if ("aaa".equals(type)) {
            logger.debug("Current branch type: aaa");
            // Branch aaa logic
        } else {
            logger.debug("Current branch type: other");
            // Default branch logic
        }

8.不要直接使用日志系统(Log4j、Logback)中的 API

在应用中，应该依赖日志框架（如SLF4J、JCL）的API，而不是直接使用具体的日志系统（如Log4j、Logback）的API。

直接使用Log4j或Logback等日志系统的API会导致系统代码与具体的日志实现强耦合，当需要切换日志实现时，会带来较大的改造成本。而使用日志框架的API，如SLF4J或JCL，它们是使用门面模式的日志框架，可以实现解耦具体的日志实现，有利于后续的维护，并确保各个类的日志处理方式保持统一。

正例：

// 使用SLF4J:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

private static final Logger logger = LoggerFactory.getLogger(MyClass.class);

// 使用JCL:
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

private static final Log log = LogFactory.getLog(MyClass.class);

9.日志工具对象 Logger 应声明为 private static final

在声明日志工具对象Logger时，应该将其修饰符设置为private static final。

正例：

private static final Logger LOGGER = LoggerFactory.getLogger(MyClass.class);

10.建议不要直接用 JSON 工具将对象转换成 String

反例：

public void doSomeThing() {
    log.info("doSomeThing and print log, data={}", JSON.toJSONString(data));
    // 业务逻辑
    ...
}

在日志打印过程中，建议不要直接使用JSON工具将对象转换成String。

正例：

可以使用 apache 的 ToStringBulider 工具，或者自定义toString方法。

public void doSomeThing() {
    log.info("doSomeThing and print log, data={}", ToStringBuilder.reflectionToString(data, ToStringStyle.SHORT_PREFIX_STYLE));
}

11.日志打印不能出现异常

在日志打印过程中，应该避免出现异常，以免影响正常的业务流程。

反例：

这个反例里直接调用了data.toString()方法来打印日志。如果data对象为null，那么在调用toString()方法时会抛出空指针异常，影响正常的业务流程。

public void doSomeThing() {
    log.info("doSomeThing and print log, data={}", data.toString());
    // 业务逻辑
    ...
}

正例：

在打印之前需要判空，或者使用Apache的ToStringBuilder工具，或者自定义toString()方法。

public void doSomeThing() {
    log.info("doSomeThing and print log, data={}", ToStringBuilder.reflectionToString(data, ToStringStyle.SHORT_PREFIX_STYLE));
    // 业务逻辑
    ...
}
public class Data {
    private String field1;
    private int field2;

    // 省略构造方法和其他方法

    @Override
    public String toString() {
        return "Data{" +
                "field1='" + field1 + '\'' +
                ", field2=" + field2 +
                '}';
    }
}

public void doSomeThing() {
    log.info("doSomeThing and print log, data={}", data);
    // 业务逻辑
    ...
}

12.敏感信息需要脱敏

为了保护用户的隐私和防止敏感信息泄露，对于一些敏感的数据，如身份证号、银行卡号等，应该进行脱敏处理，而不是明文打印。

反例：

反例里直接将身份证号idCard明文打印到日志中，这样会导致敏感信息暴露的风险。

public void doSomeThing() {
    log.info("doSomeThing and print log, idCard={}", idCard);
    // 业务逻辑
    ...
}

正例：

可以使用脱敏方法对敏感信息进行处理，来防止敏感信息泄露。

public void doSomeThing() {
    String maskedIdCard = maskIdCard(idCard);
    log.info("do something and print log, idCard={}", maskedIdCard);
    // 业务逻辑
    ...
}

private String maskIdCard(String idCard) {
    // 实现脱敏算法，将身份证号进行脱敏处理
    // 例如：将前四位和后四位保留，中间的数字用*代替
    if (idCard.length() >= 8) {
        String prefix = idCard.substring(0, 4);
        String suffix = idCard.substring(idCard.length() - 4);
        String maskedIdCard = prefix + "****" + suffix;
        return maskedIdCard;
    }
    return idCard;
}

13.建议使用异步的方式来输出日志

为了提升日志的输出性能，特别是在涉及到IO操作的情况下，建议使用异步方式来输出日志。这样可以减少IO操作的阻塞时间，提升系统的整体性能。

以logback为例，可以使用AsyncAppender来配置异步输出日志。

<appender name="FILE_ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <appender-ref ref="ASYNC"/>
</appender>

14.不要使用e.printStackTrace()

使用e.printStackTrace()存在两个问题：

正例：

应该使用日志记录框架，如logback或log4j，来打印异常信息。

try {
    // 业务代码处理
} catch (Exception e) {
    log.error("An error occurred:", e);
}

15.异常日志打印完整堆栈

反例：

异常日志没有打印完整的堆栈信息，无法提供足够的信息来排查问题。

try {
    // 业务代码处理
} catch (Exception e) {
    // 错误
    LOG.error("An error occurred:");
}

正例：

为了打印完整的堆栈信息，我们可以使用日志记录框架提供的方法，将异常对象作为参数传递给日志记录方法。

try {
    // 业务代码处理
} catch (Exception e) {
    log.error("An error occurred:", e);
}

另外，需要注意的是，使用e.getMessage()方法只能获取到异常的基本描述信息，而无法获取到完整的堆栈信息。如果需要打印完整的堆栈信息，应该使用日志记录框架提供的方法。

16.不要嵌套异常

嵌套异常会导致异常的捕获和处理变得混乱，增加问题排查的难度。在编写方法或类之前，需要提前考虑异常的处理方式，并及时回顾代码以确保异常的正确处理。

反例：

异常被嵌套捕获，导致外层的异常无法获取到真正的异常信息。

try {
    // 业务代码处理
    try {
        // 业务代码处理
    } catch (Exception e) {
        log.error("Your program has an exception", e);
    }
} catch (Exception e) {
    log.error("Your program has an exception", e);
}

正例：

为了避免嵌套异常，我们应该在合适的地方捕获和处理异常，并将异常信息记录下来。

try {
    // 业务代码处理
} catch (Exception e) {
    log.error("Your program has an exception", e);
}

17.不要记录异常又抛出

记录异常后又抛出异常是一种危险的做法。外层可能不会再次处理内层抛出的异常，导致问题无法得到正确的处理。此外，这样做还会导致堆栈信息被重复打印，浪费系统性能。

反例:

下面的反例中，异常被记录后又抛出了自定义异常。这样做的问题在于，外层可能不会再次处理内层抛出的异常，导致问题得不到正确的处理。

try {
    // 业务代码处理
} catch (Exception e) {
    log.error("IO exception", e);
    throw new MyException(e);
}

18.建议对日志配置告警

如果接入了日志分析工具，建议对日志进行告警配置。当错误日志数量超过设定的阈值时，可以及时发送告警通知，方便及时感知和排查问题。这样可以帮助我们快速发现和解决潜在的系统问题。

19.避免重复打印日志

为了提高日志的可读性和简洁性，应尽量避免重复打印日志。如果多个日志可以合并为一行来表示，可以将它们合并在一起，以减少冗余的日志输出。

反例：

log.info("User is vip, Id: {}", user);
// 冗余，可以跟前面的日志合并一起
log.info("Start solve vip, Id: {}", user);

20.不要打印无意义的日志

为了提高日志的可读性和实用性，应避免打印无意义的日志信息。无意义的日志指的是缺乏业务上下文或无关联日志链路ID的日志。

反例：

public void doSomeThing() {
    log.info("doSomeThing and print log"); // 无业务信息的日志
    // 业务逻辑
    ...
}

public void doSomeThing() {
    doIt1();
    log.info("doSomeThing 111"); // 无关联日志链路ID的日志
    doIt2();
    log.info("doSomeThing 222"); // 无关联日志链路ID的日志
}

正例：

下面是一个正例，展示了有意义的日志打印情况：

public void doSomeThing() {
    log.info("doSomeThing and print log, id={}", id); // 带有相关的业务信息的日志
    // 业务逻辑
    ...
}

在打印日志时，需要注意：

  1. 确保日志信息具有实际的业务意义，能够帮助理解和定位问题。
  2. 如果存在大量无意义的日志信息，可以考虑删除或以debug级别打印，以避免日志过于冗杂。

21.不要在循环中打印 INFO 级别日志

在循环中打印 INFO 级别的日志可能会导致日志输出过于冗杂，影响系统性能。因此，应避免在循环中打印大量的 INFO 级别日志。

反例：

下面是一个反例，展示了在循环中打印 INFO 级别日志的情况：

public void doSomeThing() {
    for(String s : strList) {
        log.info("doSomeThing and print log: {}", s);
        // 业务逻辑
        ...
    }
}

22.对于 trace/debug 级别的日志输出，必须要有开关

为了避免在配置了较高日志级别时产生不必要的日志输出，应在输出 trace/debug级别的日志之前进行相应级别的日志开关判断。

反例：

下面是一个反例，展示了没有进行日志级别开关判断的情况：

public void doSomeThing() {
    String name = "xxx";
    logger.trace("print debug log" + name);
    logger.debug("print debug log" + name);
    // 业务逻辑
    ...
}

正例：

为了避免不必要的日志输出，应在输出 trace/debug/info 级别的日志之前进行相应级别的日志开关判断。通常，可以将开关判断逻辑封装在日志工具类中，以实现统一的处理。

public void doSomeThing() {
    String name = "xxx";

    if (logger.isTraceEnabled()) {
        logger.trace("print trace log {}", name); 
    }

    if (logger.isDebugEnabled()) {
        logger.debug("print debug log {}", name); 
    }

    // 业务逻辑
    ...
}

好了，这就是本期的全部内容了，希望大家在工作中一定要好好打日志，宁愿多打，也不要少打，毕竟省的日志那一星半点，还不够一次事故的损失。

参考

Copyright© 2013-2020

All Rights Reserved 京ICP备2023019179号-8