如何高效打日志

xukun2024-11-262024-11-26

日志是我们系统出现错误时，最快速有效的定位工具，没有日志给出的错误信息，遇到报错你就会一脸懵逼；而且日志还可以用来记录业务信息，比如记录用户执行的每个操作，不仅可以用于分析改进系统，同时在遇到非法操作时，也能很快找到凶手。

因此，对于程序员来说，日志记录是重要的基本功。

一、日志记录的方法

日志框架选型

有很多 Java 的日志框架和工具库，可以帮我们用一行代码快速完成日志记录。

在学习日志记录之前，很多同学应该是通过 System.out.println 输出信息来调试程序的，简单方便。

但是，System.out.println 存在很严重的问题！

首先，System.out.println 是一个同步方法，每次调用都会导致 I/O 操作，比较耗时，频繁使用甚至会严重影响应用程序的性能，所以不建议在生产环境使用。此外，它只能输出简单的信息到标准控制台，无法灵活设置日志级别、格式、输出位置等。

所以我们一般会选择专业的 Java 日志框架或工具库，比如经典的 Apache Log4j 和它的升级版 Log4j 2，还有 Spring Boot 默认集成的 Logback 库。不仅可以帮我们用一行代码更快地完成日志记录，还能灵活调整格式、设置日志级别、将日志写入到文件中、压缩日志等。

使用日志框架

日志框架的使用非常简单，一般需要先获取到 Logger 日志对象，然后调用 logger.xxx（比如 logger.info）就能输出日志了。

最传统的方法就是通过 LoggerFactory 手动获取 Logger，示例代码如下：

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MyService {
    private static final Logger logger = LoggerFactory.getLogger(MyService.class);

    public void doSomething() {
        logger.info("执行了一些操作");
    }
}

上述代码中，我们通过调用日志工厂并传入当前类，创建了一个 logger。但由于每个类的类名都不同，我们又经常复制这行代码到不同的类中，就很容易忘记修改类名。

所以我们可以使用 this.getClass 动态获取当前类的实例，来创建 Logger 对象：

public class MyService {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    public void doSomething() {
        logger.info("执行了一些操作");
    }
}

给每个类都复制一遍这行代码，就能愉快地打日志了。

但我觉得这样做还是有点麻烦，我连复制粘贴都懒得做，怎么办？

还有更简单的方式，使用 Lombok 工具库提供的 @Slf4j 注解，可以自动为当前类生成一个名为 log 的 SLF4J Logger 对象，简化了 Logger 的定义过程。示例代码如下：

import lombok.extern.slf4j.Slf4j;

@Slf4j
public class MyService {
    public void doSomething() {
        log.info("执行了一些操作");
    }
}

此外，可以通过修改日志配置文件（比如 logback.xml 或 logback-spring.xml）来设置日志输出的格式、级别、输出路径等。

二、日志记录的最佳实践

1、合理选择日志级别

日志级别的作用是标识日志的重要程度，常见的级别有：

TRACE：最细粒度的信息，通常只在开发过程中使用，用于跟踪程序的执行路径。
DEBUG：调试信息，记录程序运行时的内部状态和变量值。
INFO：一般信息，记录系统的关键运行状态和业务流程。
WARN：警告信息，表示可能存在潜在问题，但系统仍可继续运行。
ERROR：错误信息，表示出现了影响系统功能的问题，需要及时处理。
FATAL：致命错误，表示系统可能无法继续运行，需要立即关注。

其中，用的最多的当属 DEBUG、INFO、WARN 和 ERROR 了。

建议在开发环境使用低级别日志（比如 DEBUG），以获取详细的信息；生产环境使用高级别日志（比如 INFO 或 WARN），减少日志量，降低性能开销的同时，防止重要信息被无用日志淹没。

注意一点，日志级别未必是一成不变的，假如有一天你的程序出错了，但是看日志找不到任何有效信息，可能就需要降低下日志输出级别了。

2、正确记录日志信息

当要输出的日志内容中存在变量时，建议使用参数化日志，也就是在日志信息中使用占位符（比如 {}），由日志框架在运行时替换为实际参数值。

比如输出一行用户登录日志：

// 不推荐
logger.debug("用户ID：" + userId + " 登录成功。");

// 推荐
logger.debug("用户ID：{} 登录成功。", userId);

这样做不仅让日志清晰易读；而且在日志级别低于当前记录级别时，不会执行字符串拼接，从而避免了字符串拼接带来的性能开销、以及潜在的 NullPointerException 问题。所以建议在所有日志记录中，使用参数化的方式替代字符串拼接。

此外，在输出异常信息时，建议同时记录上下文信息、以及完整的异常堆栈信息，便于排查问题：

try {
    // 业务逻辑
} catch (Exception e) {
		logger.error("处理用户ID：{} 时发生异常：", userId, e);
}

3、控制日志输出量

过多的日志不仅会占用更多的磁盘空间，还会增加系统的 I/O 负担，影响系统性能。

因此，除了根据环境设置合适的日志级别外，还要尽量避免在循环中输出日志。

可以添加条件来控制，比如在批量处理时，每处理 1000 条数据时才记录一次：

1
2
3

if (index % 1000 == 0) {
    logger.info("已处理 {} 条记录", index);
}

或者在循环中利用 StringBuilder 进行字符串拼接，循环结束后统一输出：

StringBuilder logBuilder = new StringBuilder("处理结果：");
for (Item item : items) {
    try {
        processItem(item);
        logBuilder.append(String.format("成功[ID=%s], ", item.getId()));
    } catch (Exception e) {
        logBuilder.append(String.format("失败[ID=%s, 原因=%s], ", item.getId(), e.getMessage()));
    }
}
logger.info(logBuilder.toString());

如果参数的计算开销较大，且当前日志级别不需要输出，应该在记录前进行级别检查，从而避免多余的参数计算：

1
2
3

if (logger.isDebugEnabled()) {
    logger.debug("复杂对象信息：{}", expensiveToComputeObject());
}

此外，还可以通过更改日志配置文件整体过滤掉特定级别的日志，来防止日志刷屏：

<!-- Logback 示例 -->
<appender name="LIMITED" class="ch.qos.logback.classic.AsyncAppender">
  	<!-- 只允许 INFO 级别及以上的日志通过 -->
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>INFO</level>
    </filter>
    <!-- 配置其他属性 -->
</appender>

4、把控时机和内容

很多开发者（尤其是线上经验不丰富的开发者）并没有养成记录日志的习惯，觉得记录日志不重要，等到出了问题无法排查的时候才追悔莫及。

一般情况下，需要在系统的关键流程和重要业务节点记录日志，比如用户登录、订单处理、支付等都是关键业务，建议多记录日志。

对于重要的方法，建议在入口和出口记录重要的参数和返回值，便于快速还原现场、复现问题。

对于调用链较长的操作，确保在每个环节都有日志，以便追踪到问题所在的环节。

如果你不想区分上面这些情况，我的建议是尽量在前期多记录一些日志，后面再慢慢移除掉不需要的日志。比如可以利用 AOP 切面编程在每个业务方法执行前输出执行信息：

@Aspect
@Component
public class LoggingAspect {

    @Before("execution(* com.example.service..*(..))")
    public void logBeforeMethod(JoinPoint joinPoint) {
        Logger logger = LoggerFactory.getLogger(joinPoint.getTarget().getClass());
        logger.info("方法 {} 开始执行", joinPoint.getSignature().getName());
    }
}

利用 AOP，还可以自动打印每个 Controller 接口的请求参数和返回值，这样就不会错过任何一次调用信息了。

不过这样做也有一个很重要的点，注意不要在日志中记录了敏感信息，比如用户密码。万一你的日志不小心泄露出去，就相当于泄露了大量用户的信息。

5、日志管理

随着日志文件的持续增长，会导致磁盘空间耗尽，影响系统正常运行，所以我们需要一些策略来对日志进行管理。

首先是设置日志的滚动策略，可以根据文件大小或日期，自动对日志文件进行切分。比如按文件大小滚动：

<!-- 按大小滚动 -->
<rollingPolicy class="ch.qos.logback.core.rolling.SizeBasedRollingPolicy">
    <maxFileSize>10MB</maxFileSize>
</rollingPolicy>

如果日志文件大小达到 10MB，Logback 会将当前日志文件重命名为 app.log.1 或其他命名模式（具体由文件名模式决定），然后创建新的 app.log 文件继续写入日志。

还有按照时间日期滚动：

<!-- 按时间滚动 -->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>logs/app-%d{yyyy-MM-dd}.log</fileNamePattern>
</rollingPolicy>

上述配置表示每天创建一个新的日志文件，%d{yyyy-MM-dd} 表示按照日期命名日志文件，例如 app-2024-11-21.log。

还可以通过 maxHistory 属性，限制保留的历史日志文件数量或天数：

1	<maxHistory>30</maxHistory>

这样一来，我们就可以按照天数查看指定的日志，单个日志文件也不会很大，提高了日志检索效率。

对于用户较多的企业级项目，日志的增长是飞快的，因此建议开启日志压缩功能，节省磁盘空间。

1
2
3

<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>logs/app-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
</rollingPolicy>

上述配置表示：每天生成一个新的日志文件，旧的日志文件会被压缩存储。

除了配置日志切分和压缩外，我们还需要定期审查日志，查看日志的有效性和空间占用情况，从日志中发现系统的问题、清理无用的日志信息等。

如果你想偷懒，也可以写个自动化清理脚本，定期清理过期的日志文件，释放磁盘空间。比如：

1 2	# 每月清理一次超过 90 天的日志文件 find /var/log/myapp/ -type f -mtime +90 -exec rm {} \;

6、统一日志格式

统一的日志格式有助于日志的解析、搜索和分析，特别是在分布式系统中。

我举个例子大家就能感受到这么做的重要性了。

统一的日志格式：

2024-11-21 14:30:15.123 [main] INFO  com.example.service.UserService - 用户ID：12345 登录成功
2024-11-21 14:30:16.789 [main] ERROR com.example.service.UserService - 用户ID：12345 登录失败，原因：密码错误
2024-11-21 14:30:17.456 [main] DEBUG com.example.dao.UserDao - 执行SQL：[SELECT * FROM users WHERE id=12345]
2024-11-21 14:30:18.654 [main] WARN  com.example.config.AppConfig - 配置项 `timeout` 使用默认值：3000ms
2024-11-21 14:30:19.001 [main] INFO  com.example.Main - 应用启动成功，耗时：2.34秒

这段日志整齐清晰，支持按照时间、线程、级别、类名和内容搜索。

不统一的日志格式：

2024/11/21 14:30 登录成功 用户ID: 12345
2024-11-21 14:30:16 错误 用户12345登录失败！密码不对
DEBUG 执行SQL SELECT * FROM users WHERE id=12345
Timeout = default
应用启动成功

建议每个项目都要明确约定和配置一套日志输出规范，确保日志中包含时间戳、日志级别、线程、类名、方法名、消息等关键信息。

<!-- 控制台日志输出 -->
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <!-- 日志格式 -->
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

也可以直接使用标准化格式，比如 JSON，确保所有日志遵循相同的结构，便于后续对日志进行分析处理：

1
2
3

<encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
    <!-- 配置 JSON 编码器 -->
</encoder>

此外，你还可以通过 MDC（Mapped Diagnostic Context）给日志添加额外的上下文信息，比如用户 ID、请求 ID 等，方便追踪。在 Java 代码中，可以为 MDC 变量设置值：

MDC.put("requestId", "666");
MDC.put("userId", "yupi");
logger.info("用户请求处理完成");
MDC.clear();

对应的日志配置如下：

<!-- 文件日志配置 -->
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <encoder>
        <!-- 包含 MDC 信息 -->
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - [%X{requestId}] [%X{userId}] %msg%n</pattern>
    </encoder>
</appender>

这样，每个请求、每个用户的操作一目了然。

7、使用异步日志

对于追求性能的操作，可以使用异步日志，将日志的写入操作放在单独的线程中，减少对主线程的阻塞，从而提升系统性能。

除了自己开线程去执行 log 操作之外，还可以直接修改配置来开启 Logback 的异步日志功能：

<!-- 异步 Appender -->
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>500</queueSize> <!-- 队列大小 -->
    <discardingThreshold>0</discardingThreshold> <!-- 丢弃阈值，0 表示不丢弃 -->
    <neverBlock>true</neverBlock> <!-- 队列满时是否阻塞主线程，true 表示不阻塞 -->
    <appender-ref ref="CONSOLE" /> <!-- 生效的日志目标 -->
    <appender-ref ref="FILE" />
</appender>