【搬砖工翻身做工头】基础框架 —— Slf4j+Logback日志框架

93 阅读12分钟

在项目开发过程中,贯穿到底的一条线就是程序的日志记录,优雅的程序日志可以帮助开发者查看程序运行状况、排查问题。

作为底层的搬砖工,到手的项目基本上都是已经搭建好框架的半成品,团队中的架构师或者高级工程师都已经将工地搭好,泥瓦工具准备好,搬砖工要做的只是根据产品包工头给的需求文档把砖码起来。真到了需要自己搭建的时候,虽然不至于搭建不出来,但因为平时只在最肤浅的使用层面上,搭建过程中肯定也是非常不顺畅。

对我自己而言,平时听到最多的也就是log4j/log4j2/logback/slf4j这几个单词,接触的大多项目中使用的也都是slf4j+logback这套框架,至于为什么使用这套或者这些框架之间有什么区别,还确实说不出个所以然来。

下面我们来了解一下Java生态中目前常见或常听到的几个日志框架/门面 。

日志框架区别

上面提到的log4j、log4j2、logback、Slf4j,可以再加上Common Logging和JUL(java.util.logging)。这几个东西并不全是日志框架,对于Slf4j和common logging来说,他们其实是日志的接口/门面,并无具体日志的实现,而是通过抽象一系列API,简化开发者对日志框架的使用。

Slf4J(Simple Logging Facade for Java)

从全名中可以看出,Slf4j其实是Java的一个简单日志门面(门面模式是软件工程中常用的设计模式,也被称作外观模式。为子系统的一组接口提供一个统一的高层接口,使得子系统更容易实现)。我们项目中经常使用到的 LoggerFactory.getLogger(xxx.class) 就是Slf4j提供的高层接口,使我们在开发过程中无需根据具体日志框架的实现来进行不同的操作方式(降低了日志使用成本和框架迁移成本)。

Slf4j在编译期间,静态绑定本地的Log库,因此可以在OSGI中正常使用。它是通过查找类路径下org.slf4j.impl.StaticLoggerBinder,然后在StaticLoggerBinder中进行绑定。

Common Logging

Commons Logging是通过动态查找机制,在程序运行时,使用自己的ClassLoader寻找和载入本地具体的实现。详细策略可以查看commons-logging-*.jar包中的org.apache.commons.logging.impl.LogFactoryImpl.java文件。由于Osgi不同的插件使用独立的ClassLoader,Osgi的这种机制保证了插件互相独立, 其机制限制了Commons Logging在Osgi中的正常使用。

spring-boot-starter中,引入了spring-boot-start-logging日志模块,默认使用slf4j+logback的方式。

image-20210324234909338

Logback的介绍及配置

Logback在官网给自己的定位是作为log4j的继承者successor。其划分为三大模块,logback-core是logback的底层基础;logback-classic模块则可以视作是log4j的升级版本,并且实现了slf4j的接口;logback-access模块和servlet容器(例如tomcat、jetty)集成,提供Http的网络功能。

logback-classic的使用需要引入logback-core.jar(其底层基础)和slf4j-api.jar(slf4j项目提供的api接口)。

基本使用

logback通过slf4j提供的接口进行日志操作。

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

public class Demo {
	private static final Logger logger = LoggerFactory.getLogger(Demo.class);
  
  public static void main(String[] args) {
    logger.info("日志记录");
  }
}

在上面这个demo中,并没有引入logback的相关依赖,而引入了slf4j的Logger类和LoggerFacotry类。这就是slf4j顶层接口设计的威力,对于使用者来说,不管你使用的log4j还是logback,只需要同样适用slf4j提供的API就可以进行日志输出,而slf4j和具体日志框架的集成则通过提供的slf4j的桥接包实现,例如上面截图里spring-boot-starter-logging引入的log4j-to-slf4j和jul-to-slf4j桥接包。

而logback默认通过slf4j提供日志能力,因此其桥接包已经在classic模块中了。

image-20210327135010708

运行以上demo输出一行日志记录。

image-20210327135311431

官网提供了一种打印logback内部日志的方式,我们可以通过这个日志查看调用日志打印的过程中发生了什么。

LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
        StatusPrinter.print(loggerContext);

image-20210327140419555

可以看到logback的配置搜索顺序,logback-test.xml >> logback.groovy >> logback.xml(spring配置文件可以指定logback配置文件路径),如果找不到日志,则使用默认的配置文件(BasicConfigurator),也就是我们的控制台输出日志记录。

Logback的架构

为了更好的理解logback的配置文件,而不是死记硬背配置文件的内容或简单的“cv”配置,我们通过官网简单的了解一下logback的架构。

上面提到logback划分为三个模块core/classic/access,access作为servlet容器集成提供了Http相关的能力,我们不需要特别地了解(当然有兴趣可以自行了解),我们主要了解一下官网重点介绍的core和classic模块中的一部分内容。

Logback主要由三大类构成:Logger,Appender和Layout,也就是我们配置文件中最主要的配置,这也是为什么我们要先简单了解一下其架构的原因。

Logger

Logger就是操作日志记录的工具,在使用过程中通常通过LoggerFactory.getLogger()的方式来获取Logger实例,以相同的名称或类创建的Logger引用都指向同一个实例,例如:

Logger x = LoggerFactory.getLogger("test");
Logger y = LoggerFactory.getLogger("test");

此时x和y都指向同一个Logger实例,因此我们在开发过程中,无需传递Logger对象就可以在不同的类中通过相同的Logger记录我们的日志。

这在我们分类日志的需求中是非常重要的,例如我想记录某个模块的相关日志并分类输出,就可以在相同模块不同类中通过指定相同的Logger名称来通过同一个logger实例记录日志,后续通过同一个Appender对象来接收其日志并进行打印/输出。

在有些日志框架中,带参数的日志输出方式可能是通过字符串拼接的方式进行:

logger.debug("输出参数i: " + i);

但这种方式在代码运行到这里后会有或多或少的性能损耗,因此也有这样的使用方式:

// 如果不支持debug级别则不输出
if (logger.isDebugEnabled()) {
  logger.debug("输出参数i: " + i);
}

但这样的输出显得比较笨拙,不够优雅并且代码也会变得臃肿起来。

logback提供了更好的输出方式:

logger.debug("输出参数i: {}, j: {}", i, j);

logback通过占位符的形式避免了字符串拼接带来的损耗,并且当指定的Logger不支持debug(或其他级别的日志时),则不会进行字符串的格式化,作为使用者则完全不需要去担心这些边边角角的细节。

Appender

logback还支持以不同的“目标”作为日志输出对象,所谓的”目标“,可以是控制台、文件、远程socket服务器例如MySQL等数据库,JMS甚至远程UNIX系统日志守护进程。通过指定Appender来实现这些功能。

Logger负责进行日志的操作,例如记录INFO、ERROR等级别的日志,而Appender则负责将记录下来的日志通过需要的形式进行输出。一个Logger可以有很多个Appender,也就是很多种输出方式。

以官网的例子来说,一个Logger可以指定一个Console Appender,也就是控制台输出,同时还可以指定File Appender,同时以文件的形式进行输出。在我们的业务开发过程中,用的最多也就是这两种Appender。

Layout

很多情况下,用户不仅想要自定义输出目标,还想要自定义输出格式,例如ELK日志采集,logstash可能想要采集指定格式的日志文件,此时轮到Layout发挥它的作用了,通过绑定Layout到Appender上,就可以指定Appender输出的日志格式。例如常见的PatternLayout,通过指定对应的输出模式来进行日志打印。

Logback的运行逻辑

介绍完3个很重要的组件后我们来看一下logback的运行逻辑。

  1. 过滤规则

    调用TurboFilter链,过滤器返回FilterReply.DENY则拒绝日志打印,FilterReply.NEUTRAL则往下执行,FilterReply.ACCEPT则至今进行第3步。

  2. 日志级别

    判断Logger是否支持该级别日志的输出。

  3. 创建LoggingEvent对象

    创建一个LoggingEvent对象,该对象包含了所有的参数、异常、日志级别、详细信息、时间、线程等所有信息,有些信息是懒加载的,只有在后续过程中真正使用才会实例化。

  4. 调用Appender

    logback调用应用中的所有Appender的doAppend()方法(线程安全),doAppender()方法也会调用Appender中的自定义过滤器。

  5. 格式化输出

    对输出进行格式化,例如Layout进行格式化并以字符串形式返回,但有些Appender,例如SocketAppender则是对日志进行序列化,因此这类Appender也不需要Layout。

  6. 发送LoggingEvent

    然后每个Appender将日志发送至其“目标”。

    官网提供的流程图:

    image-20210327151918186

Logback的配置

上面提到了logback的部分配置加载流程,其整个流程如下:

  1. 尝试加载logback-test.xml
  2. 没有则尝试加载logback.groovy
  3. 没有则尝试加载logback.xml
  4. 没有则尝试通过JDK1.6提供SPI机制在META-INF\services\ch.qos.logback.classic.spi.Configurator下寻找
  5. 没有则使用默认的BasicConfigurator(控制台输出Root Logger)

下面介绍一下最常使用的xml格式配置方式。

configuration

<configuration> 节点为配置文件的根节点。

<configuration debug="true" scan="true" scanPeriod="30 seconds" packagingData="true"></configuration>
  • debug属性用于标记是否打印logback本身的调试日志,默认为false
  • scan属性用于标记是否检测logback配置变动并动态加载,默认为false
  • scanPeriod属性表示多久检测一次logback配置变动,默认为每分钟一次
  • packagingData属性标记是否在日志的堆栈跟踪信息中输出jar包配置,默认为false

<configuraiton> 节点下,包含0个或多个 <appender> 节点,然后是0个或多个 <logger> 节点,跟着是最多一个 <root> 节点。

image-20210327162624878

appender

  • name属性,必填,指定appender的名称
  • class属性,必填,指定appender使用的类全限定名称

<appender> 节点下包含0个或多个 <layout> 节点用于格式化日志,0个或多个 <filter> 节点用于过滤日志。

除了以上的属性之外,其他属性可以通过JavaBean的方式根据指定的class类注入,例如RollingFileAppender指定file属性等。

image-20210327171029303

layout

<layout> 有一个必填的class属性,其他根据给定的class进行JavaBean形式的属性注入。

logger

  • name属性,必填,指定logger的名称
  • level属性,可选,指定日志级别,可选值为TRACE/DEBUG/INFO/WARN/ERROR/ALL/OFF,或INHERITED/NULL表示继承父类日志级别
  • additivity属性,可选,指定false以只在该logger中打印,而不在父类logger中重复打印

<logger> 属性还包含0个或多个 <appender-ref> 节点,表示使用哪些Appender进行日志的输出。

root

只支持设置level属性,因为对于RootLogger来说,名称已经被指定了ROOT,且additivity对其没有意义。

同样root节点也包含0个或多个 <appender-ref> 节点。

常用配置

ConsoleAppender

输出日志到控制台。

  • <encoder>:对日志进行格式化
  • <target>:System.out或System.err,默认为System.out

FileAppender

输出日志到文件。

  • <file>:被写入的文件名
  • <append>:true则日志追加到文件结尾
  • <encoder>:对日志进行格式化
  • <prudent>:true则安全写入文件,即使其他的FileAppender也在向此文件做写入操作,效率低,默认为false

RollingFileAppender

输入日志到滚动记录文件。

  • <file>:被写入的文件名
  • <append>:true则日志追加到文件结尾
  • <encoder>:对日志进行格式化
  • <rollingPolicy>:当发生滚动时,决定 RollingFileAppender 的行为,涉及文件移动和重命名。
  • <triggeringPolic>:告知 RollingFileAppender 何时激活滚动。
  • <prudent>:当为true时,不支持FixedWindowRollingPolicy。支持TimeBasedRollingPolicy,但是有两个限制,1不支持也不允许文件压缩,2不能设置file属性,必须留空。
rollingPolicy
TimeBasedRollingPolicy

最常用的滚动策略,它根据时间来制定滚动策略,既负责滚动也负责触发滚动。

RollingFileAppender 的file字节点可有可无,通过设置file,可以为活动文件和归档文件指定不同位置,当前日志总是记录到file指定的文件(活动文件),活动文件的名字不会改变;如果没设置file,活动文件的名字会根据fileNamePattern 的值,每隔一段时间改变一次。“/”或者“\”会被当做目录分隔符。

  • <fileNamePattern>:必要节点,包含文件名及“%d”转换符, “%d”可以包含一个java.text.SimpleDateFormat指定的时间格式,如:%d{yyyy-MM}。如果直接使用 %d,默认格式是 yyyy-MM-dd。
  • <maxHistory>:可选节点,控制保留的归档文件的最大数量,超出数量就删除旧文件。假设设置每个月滚动,且<maxHistory>是6,则只保存最近6个月的文件,删除之前的旧文件。
FixedWindowRollingPolicy

根据固定窗口算法重命名文件的滚动策略。

  • <minIndex>:窗口索引最小值
  • <maxIndex>:窗口索引最大值,当用户指定的窗口过大时,会自动将窗口设置为12
  • <fileNamePattern>:必须包含“%i”例如,假设最小值和最大值分别为1和2,命名模式为 mylog%i.log,会产生归档文件mylog1.log和mylog2.log。还可以指定文件压缩选项,例如mylog%i.log.gz 或者 log%i.log.zip。
triggeringPolicy
SizeBasedTriggeringPolicy

查看当前活动文件的大小,如果超过指定大小会告知 RollingFileAppender 触发当前活动文件滚动。

  • <maxFileSize>:这是活动文件的大小,默认值是10MB

参考文章