Java 日志

概述

Java日志系统中，有两个组件协同工作

  • 一个是负责日志输出的框架，如Logback、Log4j2
  • 一个是日志接口，提供统一的日志记录接口，如slf4j、Apache commons-logging

日志接口必须与日志输出框架集成后才能正常工作，集成时，需要相应的桥接包，以slf4j为例，

集成log4j2时需要如下包

  • slf4j-api
  • log4j-api、log4j-core、log4j-slf4j-impl(集成包)

集成logback时需要如下包

  • slf4j-api
  • logback-core、logback-classic(集成包)

除了日志接口与输出框架的集成，日志接口之间也可以进行转接。

例如将commons-logging接口转接到slf4j，再由slf4j集成到logback。

  • jcl-over-slf4j(集成包，不再需要commons-logging)
  • slf4j-api、logback-core、logback-classic(集成包)

以常用的Slf4j+Logback的组合来说，我们在程序中进行日志打印时，调用的是Slf4j中的Log对象进行日志记录，但是真正进行日志输出的其实是Logback，如输出到控制台、文件。

日志系统

使用Slf4j作为统一的日志接口，集成日志输出框架Logback，同时转接commons-logging接口，包依赖如下

  • jcl-over-slf4j
  • slf4j-api、logback-core、logback-classic

Slf4j

引入slf4j-api包以后，有两种使用方式，一是在类中定义一个Slf4j Logger对象，二是直接使用lombok的@Slf4j注解。

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

public class HelloWorld{
  private static final Logger logger = LoggerFactory.getLogger(HelloWorld.class);
  public static void main(String[] args) {
    logger.info("hello rachel !");
  }
}

Logback

引入logback-core、logback-classic包后，slf4j会自动与其集成。springboot可以自动识别加载logback配置，但要符合命令规则，如logback.xml，logback-spring.xml等。

编写配置文件logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <!--引入spring boot默认的logback配置文件，使用其中定义的日志打印格式-->
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>

    <!--标准输出：控制台日志-->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <!-- spring property：自定义属性，引用spring上下文中的值 -->
<springProperty scope="context" name="LOG_PATH" source="logging.file.path" defaultValue="logs"/>
    <springProperty scope="context" name="LOG_LEVEL" source="logging.level" defaultValue="INFO"/>
    <springProperty scope="context" name="APP_NAME" source="spring.application.name" defaultValue="zhisou"/>

    <!--文件输出：追加日志到文件中-->
<appender name="LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--实时日志文件的存放路径和名称-->
<file>${LOG_PATH}/${APP_NAME}.log</file>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>

        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!--滚动切割产生的历史日志文件的存放路径和名称-->
            <!--%d{yyyy-MM-dd}：按天进行日志滚动-->
            <!--%i：当文件大小超过maxFileSize时，按照i进行文件滚动-->
<fileNamePattern>${LOG_PATH}/${APP_NAME}.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!--历史日志保存最大天数-->
<MaxHistory>15</MaxHistory>
            <!--当日志文件超过指定的大小时，根据FileNamePattern标签里提到的%i进行日志文件滚动-->
<maxFileSize>100MB</maxFileSize>
        </rollingPolicy>
    </appender>

    <!--日志级别从低到高分为TRACE < DEBUG < INFO < WARN < ERROR < FATAL，配置INFO表示只会记录自身和比高于自身级别的日志-->
    <!--开发调试阶段打开控制台输出，日志级别设置为INFO；生产环境关闭控制台输出，只需要将WARN及以上级别的日志记录到文件中-->
    <!--root为根logger配置（其余logger都是它的子类），用于定义要记录的日志级别和日志输出目的地-->
<root level="${LOG_LEVEL}">
        <!--定义日志输出，控制台和日志文件-->
<appender-ref ref="STDOUT"/>
        <appender-ref ref="LOG_FILE"/>
    </root>

    <!-- 定义子logger，针对org.springframework包下产生的日志只记录WARN及以上级别 -->
    <!--    <logger name="org.springframework" level="WARN"/>-->

</configuration>

问题

logback-spring.xml中引用spring上下文内容时，如果该配置在本地，可以在加载logback-spring.xml时引用配置值。但如果该配置项在配置中心上，会无法引用，只能使用默认值。

因为使用默认的日志文件命名时（logback.xml和logback-spring.xml），spring在获取远程配置之前就已经加载logback.xml，而此时要引用的spring配置还没加载。

<springProperty scope="context" name="APP_NAME" source="spring.application.name" defaultValue="zhisou"/>

解决方法：使用自定义的日志文件名（spring无法自动加载），如logback-custom.xml。然后在远程配置中指定使用该配置文件，这样就可以在远程配置加载后再加载logback配置。

# 这里classpath指resources目录下
logging.config: classpath:logback-custom.xml

Logback深入

结构

logback主要由appender和logger两部分构成

  • appender用于负责日志输出，例如，输出到控制台或者文件、定制输出格式。
  • logger用于指定某一个包或者类中的日志输出级别，以及指定appender。root代表的是根logger，其余的logger皆继承root中的配置。

Appender

appender标签中，需要指定一个名字和appender类。根据appender类的不同，有不同的行为，例如输出到控制台或者文件。

控制台

ConsoleAppender就是用于输出日志到控制台的，日志输出到控制台时是一种滚动输出的方式，旧的日志很快会被新的覆盖。在appender中定义一个encoder对象，确定日志输出格式和字符编码即可。

<!--标准输出：控制台日志-->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>
文件输出

相较于控制台输出，输出到文件中就复杂多了。

例如，是始终输出到一个文件呢？还是按照一定的规则，输出到不同的文件中？

输出到一个文件中，会导致文件越来越庞大，不是一个好的选择，所以一般选择是输出到不同文件中。

输出到不同文件中时，按照什么规则进行文件分割呢？文件大小？时间？又或者是两者结合？

分割规则一般基于时间和文件大小的结合，只要有一个符合条件，就新建一个日志文件用于存储日志。

具体的实现是通过滚动输出类RollingFileAppender，结合基于大小和时间的滚动规则使用SizeAndTimeBasedRollingPolicy。

<!--文件输出：追加日志到文件中-->
<appender name="LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!--实时日志文件的存放路径和名称-->
<file>${LOG_PATH}/${APP_NAME}.log</file>
        <encoder>
            <pattern>${FILE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>

        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <!--滚动切割产生的历史日志文件的存放路径和名称-->
            <!--%d{yyyy-MM-dd}：按天进行日志滚动-->
            <!--%i：当文件大小超过maxFileSize时，按照i进行文件滚动-->
<fileNamePattern>${LOG_PATH}/${APP_NAME}.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <!--历史日志保存最大天数-->
<MaxHistory>30</MaxHistory>
            <!--当日志文件超过指定的大小时，根据FileNamePattern标签里提到的%i进行日志文件滚动-->
<maxFileSize>100MB</maxFileSize>
        </rollingPolicy>
    </appender>

Logger

这里的Logger相当于我们在类中定义的Logger对象，我们可以单独为每一个类中的Logger对象指定一个Appender，但这可能会累死人，并且没有收益。

更好的方法是通过root对象，root代表的是一个根Logger对象，其余的Logger对象都是它的子类，所以只要在root中定义了Appender，就相当于对所有Logger设置了。

如果对某些包中进行单独的配置，只需要再定义一个Logger，重写配置即可。

<!--日志级别从低到高分为TRACE < DEBUG < INFO < WARN < ERROR < FATAL，配置INFO表示只会记录自身和比高于自身级别的日志-->
    <!--开发调试阶段打开控制台输出，日志级别设置为INFO；生产环境关闭控制台输出，只需要将WARN及以上级别的日志记录到文件中-->
    <!--root为根logger配置（其余logger都是它的子类），用于定义要记录的日志级别和日志输出目的地-->
<root level="${LOG_LEVEL}">
        <!--定义日志输出，控制台和日志文件-->
<appender-ref ref="STDOUT"/>
        <appender-ref ref="LOG_FILE"/>
    </root>

    <!-- 定义子logger，针对org.springframework包下产生的日志只记录WARN及以上级别 -->
    <logger name="org.springframework" level="WARN"/>

高级应用

异步输出

cache和buffer的区别

  • cache ：设备之间有速度差，高速设备访问低速设备会造成高速设备等待，导致使用率降低，为了减少低速设备对高速设备的影响，在两者之间加入cache，通过加快访问速度，以提升高速设备的使用效率。
  • buffer ：通俗来说就是化零为整，把少量多次变成多量少次；具体来说就是进行流量整形，把突发的大数量较小规模的 I/O 整理成平稳的小数量较大规模的 I/O，以减少响应次数

logback中的FileAppender就是一种buffer级的输出方案，其内部有一个buffer。在进行日志写入时，如果buffer还未写满就写入buffer中，如果buffer满了，就先将buffer同步写入磁盘，再写buffer。

logback中还提供了一种cache级的方案AsyncAppender，其适用场景为高并发环境下。AsyncAppender内部有一个阻塞队列，每次日志写入时，就将其放入到阻塞队列中；由一个后台线程，从阻塞队列中取数据，放入下游的FileAppender。

<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <discardingThreshold>0</discardingThreshold>
    <queueSize>1000</queueSize>
    <!-- 绑定一个FileAppender -->
    <appender-ref ref="FILE_APPEND" />
    <!-- 与MDC搭配使用，复制MDC中的信息到异步线程-->
    <includeCallerData>true</includeCallerData>
  </appender>

链路追踪

微服务中，一个请求在多个服务中日志如何串联起来分析？

一个方法是为每个请求生成一个traceId，然后放入request对象中，在不同的服务中进行日志输出时，都输出这个traceId。这个traceId可以是一个UUID，也可以根据服务名+请求IP+时间戳进行生成，只要唯一即可。

有了traceId，那怎么做到每次日志输出时，都输出这个traceId呢？

Logback提供了一种上下文信息存储机制MDC（Mapped Diagnostic Context），可以在日志输出时动态添加一些额外的上下文信息。例如，将traceId放入MDC中，然后在日志输出格式中引用traceId即可。因为MDC基于ThreadLocal实现，可以线程执行的任意地方获取到MDC中的信息。

一个可行的链路追踪方案是，在每个服务中都定义一个ServletFilter，检测request对象中是否存在一个约定好的traceId字段，如果存在，放入MDC中；如果不存在，则生成一个，放入request对象中，也放入MDC中。

TraceFilter

public class TraceFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {

        String traceId = request.getHeader("x-trace-id");
        if (StringUtils.isEmpty(traceId)) {
            // 更好的实现是基于服务名+请求IP+时间戳生成traceId
            traceId = UUID.randomUUID().toString();    
        }
        
        MDC.put("x-trace-id", traceId);
        filterChain.doFilter(request, response);
        MDC.remove("x-trace-id");
    }
}

日志格式定义

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>[%X{traceId}]-[%d]-[%-5p]-[%t]-[%c:%L]</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

配置含义为

  • [%X{traceId}]: 输出MDC中名为traceId的值。
  • [%d]: 输出日志事件的时间戳，默认使用ISO8601格式。
  • [%-5p]: 输出日志事件的级别，左对齐并固定宽度为5个字符。级别包括TRACE、DEBUG、INFO、WARN、ERROR等。
  • [%t]: 输出产生日志事件的线程名称。
  • [%c:%L]: 输出产生日志事件的类名和行号。%c表示类名，%L表示行号。
  • %m: 输出日志事件的消息。
  • %n: 输出一个换行符。
  • %wEx: 输出日志事件的异常信息，包括异常类名、异常消息和堆栈跟踪。

信息传递

需要注意的问题是，在服务中涉及到线程切换或者接口调用时，需要将traceId信息复制到子线程或者请求对象中。

例如，在线程池中传递traceId，通过Feign Client调用其它服务时需要将traceId放入request header中。

posted @   cd_along  阅读(14)  评论(0)  编辑  收藏  举报
相关博文：
· Java 多线程编程基础
· Openfeign集成Ribbon、Hystrix原理解析
· Java的日志框架之Logback
· Java日志技术快速入门
· java 日志框架总结
阅读排行：
· 分享4款.NET开源、免费、实用的商城系统
· 全程不用写代码，我用AI程序员写了一个飞机大战
· MongoDB 8.0这个新功能碉堡了，比商业数据库还牛
· 白话解读 Dapr 1.15：你的「微服务管家」又秀新绝活了
· 上周热点回顾（2.24-3.2）
历史上的今天：
2021-06-01 JVM 内存区域
点击右上角即可分享
微信分享提示