SLF4J 探秘

SLF4J 设计与实现

Posted by John Mactavish on April 26, 2021

SLF4J 指的是 Simple Logging Facade for Java,其中的 Facade 指的是门面模式(或者叫外观模式)的门面。 为什么要设计这样的门面呢?我们知道,日志模块是大多数 Java 程序必备的模块,而日志的实现可以有很多种, 比如有的日志注重持久性,会频繁刷写数据到磁盘上;还有的日志支持对接数据库等。一个项目可能会根据需求变化中途 更改日志实现,多个项目也可能会使用不同的日志实现。不同日志实现的 API 一般不同,这无疑增加了项目与日志模块之间的耦合性。 解耦的方法一般都是增加中间抽象层。SLF4J 就是这样的抽象层。它提供日志接口供外部使用,而接口内部依赖具体日志模块实现。

我们对于使用接口的认知一般是这样的:

LoggerInterface logger = new ConcreteLogger();

但是自己创建 ConcreteLogger 还是引入了应用与具体日志模块的耦合。我们希望 SLF4J 最好可以自己找到实现类。 那么 SLF4J 要怎么找到具体的日志模块实现呢?我们先看看一个类似的库 Apache Commons Logging (JCL) 的实现, 以下步骤从前到后,只要某一步成功了就不再向下继续。

1. 首先在 classpath 下寻找自己的配置文件 commons-logging.properties,如果找到,则使用其中定义的 Log 实现类 2. 如果找不到 commons-logging.properties 文件,则查找是否存在系统环境变量 org.apache.commons.logging.Log,如找到则使用其定义的 Log 实现类 3. 查看 classpath 中是否有 Log4j(一个常用的的日志模块实现)包,如有则自动使用 Log4j 作为日志实现类 4. 使用 JDK 自身的日志实现类(JDK 1.4 以后才有日志实现类) 5. 使用 commons-logging 自带的一个简单的日志实现类 SimpleLog

参考 JCL 的文档

个人认为这种实现有两个缺点:

  • 远行时的查找规则略显复杂,且不够清晰明确(explicit
  • 与具体实现类耦合(JCL 知晓 Log4j

相比之下,SLF4J 的查找策略要更清晰干净一些。虽然它自己就是上层应用与底层具体日志模块间的中间层,但它还在自己与底层间又引入了一个中间层。 这个中间层包装具体实现,对外提供相同的接口供 SLF4J 使用。如此一来,SLF4J 变成了纯粹的接口层,与具体日志完全无耦合。

comparison

图源某博客

接下来让我们来看看 SLF4J 具体是怎样工作的。

我们新建一个 Java 项目,使用 gradle 进行依赖管理, 查询 Maven Repository 得到 SLF4J 接口层的依赖如下:

// build.gradle

// ...
dependencies {
    // ...

    implementation group: 'org.slf4j', name: 'slf4j-api', version: '1.7.30'
}

然后写一个实例如下:

package fun.mactavish.athos;

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

public class Demo {
    private static final Logger l = LoggerFactory.getLogger(Demo.class);

    public static void main(String[] args) {
        l.error("hello");
    }
}

运行一下,发现控制台输出:

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

它告诉我们未找到具体的日志实现类,所以使用了默认的空实现。这表明了 SLF4J 本身确实只是一个接口层。 我们接下来添加一个具体的日志实现类的依赖:

// build.gradle

// ...
dependencies {
    // ...

    implementation group: 'org.slf4j', name: 'slf4j-api', version: '1.7.30'

    // log4j
    implementation group: 'org.apache.logging.log4j', name: 'log4j-slf4j-impl', version: '2.14.1'
}

重启程序,输出正常:

17:11:08.225 [main] ERROR fun.mactavish.athos.Demo - hello

同时,我们也能发现,LoggerFactory.getLogger(Demo.class) 调用中传入的自己的 Class 对象是为了在日志中记录自己的身份。

让我们 debug 一下,跟着 LoggerFactory.getLogger(Demo.class) 的调用链看看发生了什么。

源码解析基于 org.slf4j:slf4j-api:1.7.30;源码可能随版本而变,你不能基于它对程序行为进行任何假设,你能依靠的只有文档; 源码解析仅用于学习大致实现思路。

调用链如下:

// all in class LoggerFactory

public static Logger LoggerFactory.getLogger(Class<?> clazz)

public static Logger getLogger(String name)

public static ILoggerFactory getILoggerFactory()

private final static void performInitialization()

private final static void bind()

LoggerFactory 通过字段 static volatile int INITIALIZATION_STATE 保存自身状态。在初次调用 getILoggerFactory 方法时, 发现状态为 UNINITIALIZED 就会进行初始化。bind 方法中与具体实现类发生了绑定。

private final static void bind() {
    try {
        Set<URL> staticLoggerBinderPathSet = null;
        // skip check under android, see also
        // http://jira.qos.ch/browse/SLF4J-328
        if (!isAndroid()) {
            staticLoggerBinderPathSet = findPossibleStaticLoggerBinderPathSet();
            reportMultipleBindingAmbiguity(staticLoggerBinderPathSet);
        }
        // the next line does the binding
        StaticLoggerBinder.getSingleton();
        INITIALIZATION_STATE = SUCCESSFUL_INITIALIZATION;
        reportActualBinding(staticLoggerBinderPathSet);
    } catch (NoClassDefFoundError ncde) {
        String msg = ncde.getMessage();
        if (messageContainsOrgSlf4jImplStaticLoggerBinder(msg)) {
            INITIALIZATION_STATE = NOP_FALLBACK_INITIALIZATION;
            Util.report("Failed to load class \"org.slf4j.impl.StaticLoggerBinder\".");
            Util.report("Defaulting to no-operation (NOP) logger implementation");
            Util.report("See " + NO_STATICLOGGERBINDER_URL + " for further details.");
        } else {
            failedBinding(ncde);
            throw ncde;
        }
    } catch (java.lang.NoSuchMethodError nsme) {
        String msg = nsme.getMessage();
        if (msg != null && msg.contains("org.slf4j.impl.StaticLoggerBinder.getSingleton()")) {
            INITIALIZATION_STATE = FAILED_INITIALIZATION;
            Util.report("slf4j-api 1.6.x (or later) is incompatible with this binding.");
            Util.report("Your binding is version 1.5.5 or earlier.");
            Util.report("Upgrade your binding to version 1.6.x.");
        }
        throw nsme;
    } catch (Exception e) {
        failedBinding(e);
        throw new IllegalStateException("Unexpected initialization failure", e);
    } finally {
        postBindCleanUp();
    }
}

我们留意一下 findPossibleStaticLoggerBinderPathSet 这个方法,它获取了 LoggerFactoryClassLoader, 然后利用它获取了 classpath 中所有的 org/slf4j/impl/StaticLoggerBinder.class(这就是 SLF4J 自己引入的新的中间层)。你以为它接下来要自己加载具体实现类吗,不, 这个方法只是方便下面向用户进行警示。假如我们引入了多个具体实现的依赖,那也只会有一个实现真正地加载进 JVM, 但这种行为明显有隐患(implicit and ambiguous)。JVM 不会对自己的这一行为进行告警,于是 SLF4J 自己检查一下。

那么绑定发生在哪儿呢?正如注释所写,发生在 org.slf4j.impl.StaticLoggerBinder.getSingleton() 这儿。 这行代码不关心返回值,利用的是对 JVM 的副作用(side effect)。 这行代码对应的字节码理论上是程序中第一次引用 org.slf4j.impl.StaticLoggerBinder 这个符号的地方, 这会导致 JVM 尝试搜寻 org.slf4j.impl.StaticLoggerBinder 并加载这个类。 我们查看一下 org.apache.logging.log4j:log4j-slf4j-impl:2.14.1 的源码, 它的包声明正是 org.slf4j.impl,因此在使用 log4j-slf4j-impl 依赖时, JVM 自动加载的就是包装了 log4jorg.slf4j.impl.StaticLoggerBinder。如果改用依赖 org.slf4j:slf4j-jdk14:1.7.30, 不难发现包声明也是 org.slf4j.impl,此时 JVM 自动加载的将是包装了 jdk14 日志实现类的 org.slf4j.impl.StaticLoggerBinder。 如果不提供任何额外依赖,显然 JVM 就找不到 org.slf4j.impl.StaticLoggerBinder,触发 NoClassDefFoundError 异常, 然后 SLF4J 利用 Util.report(String msg)stderr 输出错误信息并切换至默认的空日志实现。

最后用一张 SLF4J 文档中的图总结一下它的工作原理:

design


如果你喜欢我的文章,请我吃根冰棒吧 (o゜▽゜)o ☆

contribution

最后附上 GitHub:<https://github.com/gonearew