解决Slf4j日志不打印问题

2年前 (2022) 程序员胖胖胖虎阿

276 0 0

日志不打印的问题，很让人头疼，也是我们经常遇到的问题。

日常站点状态巡检时发现有异常日志，定位到日志位置，看其上线文自定义输出的日志时却发现，自己加的日志都没输出。排查了一下初步定位到，这个类中日志输出使用的lombok的@Slf4j注解的功能，浏览了一下其他使用该注解的类，自定义加的日志也都在线上没打印。而使用LoggerFactory.getLogger(Class<?> clazz)获取的Logger对象打印的日志，在线上能正常打印。

本地启动，使用的lombok的@Slf4j注解的类，日志也能打印，测试环境也可以。就很奇怪！

有点经验的都会猜到，jar包冲突导致的。

怎么验证以及解决呢？

maven依赖树日志

首先可以用maven的命令mvn dependency:tree

如下，将maven依赖树输出到文件，方便查看和检索

mvn dependency:tree > log.txt

可以搜索log等关键词，看除了自己引的log包以外，还有没有通过其他第三方包间接引入了其他版本或其他日志实现的jar（如，你使用的log4j，你依赖的一个第三方包里依赖了logback等）。通过这种方式可以排查出大部分冲突的依赖。

如，我引入了zkClient的包，它依赖的log版本和我的不一样
解决Slf4j日志不打印问题

我就可以通过如下方式排除它的jar里的log包。还有其他的也一样排除掉，这里没有意义列举。

<dependency>
    <groupId>com.101tec</groupId>
    <artifactId>zkclient</artifactId>
    <version>0.4</version>
    <exclusions>
        <exclusion>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
        </exclusion>
    </exclusions>
</dependency>

Slf4j绑定日志实现的原理

这种方式找起来其实不那么方便，看了这位老哥的博文，明白了冲突的原理。大概引用一下原文吧

系统使用的是SLF4J框架打印log4j2的日志。查看系统中引入的jar包发现果然有多个SLF4J的桥接包。于是排掉冲突jar包，然后上线时所有机器都正常打印日志。

我们都知道，SLF4J是一个日志门面，下图是SLF4J框架、各种具体日志实现以及相应桥接包的关系图，来源于那篇文章。

解决Slf4j日志不打印问题
SLF4J框架作为门面框架，并没有日志的具体实现。而是通过和其他具体日志实现进行关联转换，并在系统中配置一种日志实现进行打印。

于是就很容易造成jar包引入冲突，导致有多个日志实现。当SLF4J框架选择的日志实现和我们配置的不一致时，就会打印不出日志。

SLF4J框架发现有多个日志实现时，是会打印提示信息的。但由于是标准错误输出，会在控制台（Tomcat的catalina.out）中打印【当业务日志文件中没有日志打印时，可以查看catalina.out是否有提示】
解决Slf4j日志不打印问题

因为每个SLF4J的桥接包都有org.slf4j.impl.StaticLoggerBinder，而SLF4J则会随机选择一个使用。当选择的跟系统配置的一样时就可以打印日志，否则就打印不出。所以就会出现有的机器打印日志，而有的机器可能就不打印日志。
解决Slf4j日志不打印问题

快速感知是否存在多个桥接包

刚才通过maven依赖树肉眼找的方式，不是太方便，了解了Slf4j绑定日志实现的原理，我们就可以通过调用其findPossibleStaticLoggerBinderPathSet方法的返回的Set集合获取当前有多少个桥接包，然后再通过再依赖树输出的日志里搜索具体的包名。

具体方式：

实现spring的BeanFactoryPostProcessor，并将其交由spring管理。保证系统启动后，自动进行日志冲突校验。
使用反射获取LoggerFactory的实例以及findPossibleStaticLoggerBinderPathSet方法的返回结果。
根据桥接包数量判断是否异常，进行自定义报警。
根据报警信息，在依赖树日志中搜索，看是从那个依赖中间接引入的，然后进行排包。

import org.apache.commons.collections4.CollectionUtils;
import org.slf4j.LoggerFactory;
import org.springframework.beans.BeansException;
import org.springframework.beans.factory.config.BeanFactoryPostProcessor;
import org.springframework.beans.factory.config.ConfigurableListableBeanFactory;
import org.springframework.stereotype.Component;

import java.lang.reflect.Constructor;
import java.lang.reflect.Method;
import java.net.InetAddress;
import java.net.URL;
import java.util.Set;

/**
 * 日志jar包冲突校验
 */
@Component
public class LogJarConflictCheck implements BeanFactoryPostProcessor {
    @Override
    public void postProcessBeanFactory(ConfigurableListableBeanFactory configurableListableBeanFactory) throws BeansException {
        try {
            Class<LoggerFactory> loggerFactoryClazz = LoggerFactory.class;
            Constructor<LoggerFactory> constructor = loggerFactoryClazz.getDeclaredConstructor();
            constructor.setAccessible(true);
            LoggerFactory instance = constructor.newInstance();
            Method method = loggerFactoryClazz.getDeclaredMethod("findPossibleStaticLoggerBinderPathSet");
            // 强制进入
            method.setAccessible(true);
            Set<URL> staticLoggerBinderPathSet = (Set<URL>)method.invoke(instance);
            if (CollectionUtils.isEmpty(staticLoggerBinderPathSet)) {
                handleLogJarConflict(staticLoggerBinderPathSet, "Class path is Empty.添加对应日志jar包");
            }
            if (staticLoggerBinderPathSet.size() == 1) {
                return;
            }
            handleLogJarConflict(staticLoggerBinderPathSet, "Class path contains multiple SLF4J bindings. 注意排包");
        } catch (Throwable t) {
            t.getStackTrace();
        }
    }
    /**
     * 日志jar包冲突报警
     * @param staticLoggerBinderPathSet jar包路径
     * @param tip 提示语
     */
    private void handleLogJarConflict (Set<URL> staticLoggerBinderPathSet, String tip) {
        String ip = getLocalHostIp();
        StringBuilder detail = new StringBuilder();
        detail.append("ip为").append(ip).append("; 提示语为").append(tip);
        if (CollectionUtils.isNotEmpty(staticLoggerBinderPathSet)) {
            String path = JsonUtils.toJson(staticLoggerBinderPathSet);
            detail.append("; 重复的包路径分别为 ").append(path);
        }
        String logDetail = detail.toString();
		//可以自定义告警
        System.out.println("====>"+logDetail);
    }

    private String getLocalHostIp() {
        String ip;
        try {
            InetAddress addr = InetAddress.getLocalHost();
            ip = addr.getHostAddress();
        } catch (Exception var2) {
            ip = "";
        }
        return ip;
    }
}

通过配置一劳永逸

上面的方式也只是帮助我们快速感知到日志jar包冲突，仍需手动排包。

是否存在一种解决方法，能帮忙我们彻底解决这种问题呢？

答案是有。

即将我们需要引入的jar包和需要排掉的jar包声明到maven的最上层，将需要排掉的包声明为provided即可

这种方案是利用maven的扫包策略：

依赖最短路径优先原则；
依赖路径相同时，申明顺序优先原则

当我们将所有jar包声明为直接依赖后，会优先被使用。而我们需要排掉的包只要声明为provided，就不会打入包中。从而实现需要的包以我们声明的为准，需要排掉的包也不会被间接依赖影响

<properties>
  <slf4j.version>1.7.7</slf4j.version>
    <logback.version>1.2.3</logback.version>
    <log4j.version>1.2.17</log4j.version>
    <log4j2.version>2.3</log4j2.version>
    <jcl.version>1.2</jcl.version>
</properties>
<dependencies>
    <!--系统使用log4j2作为系统日志实现 slf4J作为门面 -->
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>${slf4j.version}</version>
    </dependency>
    <!--使用log4j2作为实际的日志实现-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <version>${log4j2.version}</version>
    </dependency>
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>${log4j2.version}</version>
    </dependency>
    <!--将log4j、logback、JCL的jar包设置为provided，不打入包中-->
    <dependency>
        <groupId>log4j</groupId>
        <artifactId>log4j</artifactId>
        <version>${log4j.version}</version>
        <scope>provided</scope>
    </dependency>
    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
        <version>${logback.version}</version>
        <scope>provided</scope>
    </dependency>
    <dependency>
        <groupId>commons-logging</groupId>
        <artifactId>commons-logging</artifactId>
        <version>${jcl.version}</version>
        <scope>provided</scope>
    </dependency>
    <!--为防止循环转换，排掉log4j2转slf4j的桥接包-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-to-slf4j</artifactId>
        <version>${log4j2.version}</version>
        <scope>provided</scope>
    </dependency>
    <!--声明log4j、JCL、JUL转slf4j的桥接包，代码中对应日志可以转成SLF4J-->
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>log4j-over-slf4j</artifactId>
        <version>${slf4j.version}</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>jcl-over-slf4j</artifactId>
        <version>${slf4j.version}</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>jul-to-slf4j</artifactId>
        <version>${slf4j.version}</version>
    </dependency>
    <!--声明slf4j转SLF4J的桥接包-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>${log4j2.version}</version>
    </dependency>
    <!--排掉slf4j转log4j、JCL、JUL转slf4j的桥接包的桥接包，防止日志实现jar包冲突-->
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-log4j12</artifactId>
        <version>${slf4j.version}</version>
        <scope>provided</scope>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-jdk14</artifactId>
        <version>${slf4j.version}</version>
        <scope>provided</scope>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-jcl</artifactId>
        <version>${slf4j.version}</version>
        <scope>provided</scope>
    </dependency>
</dependencies>