Spring杂谈之SpringBoot统一日志处理

SpringBoot作为日常开发利器,开箱即用,大量的star等已经成为节省开发的重要框架之一,但是各个框架的
star中引入的日志框架却不尽相同,有的是log4j,有的是slf4j,这导致我们在引入多个框架的star的时候,往
往会引入多个日志框架,每一个日志框架彼此效率不尽相同,那么我们能不能做到在项目中仅引入一个统一
的日志框架呢?本篇我们就来探索SpringBoot如何实现统一日志操作

为什么需要日志

首先我们需要明白,日志的作用是什么--即用来在程序运行过程中,将我们需要的信息打印出来,便于我们在调试中查找和观察。在JAVA中存在很多常见的日志框架,如JUL、JCL、Jboss-logging、log4j、logback、slf4j等,这么多日志框架,我们该如何选择?

日志门面与日志实现

在日志框架选型之前,我们先了解一个概念,什么是日志门面?日志门面,不是具体的日志解决方案,它只服务于各种各样的日志系统,允许最终用户在部署其应用时使用其所希望的日志实现来使用日志功能。而日志实现则是基于对应的日志门面的规范来实现的具体日志功能的框架,常见的日志门面与日志实现关系如下:

日志门面 日志实现
JCL、SLF4j、jboss-logging Log4j、 JUL(java.util.logging) Log4j2、 Logback

每一种日志框架输出信息的效率也不尽相同,而我们日常开发使用的框架中往往都会引入一个日志框架来辅助输出框架信息,然而框架之间由于历史迭代原因及框架性能等问题,选择的日志框架也不一样,常见的框架与默认选择的日志系统关系如下:

框架 日志
Spring JCL
SpringBoot Sfl4j-->logback
Hibernate3 Slf4j
Struts2 LoggerFactory(com.opensymphony.xwork2.util.logging.LoggerFactory)

由于历史迭代原因,JCL和jboss-logging日志框架,基本已经很久没有更新了,不太适合作为现在框架的主流选择,那么剩下的选择中log4j、slf4j是使用最多的,然而由于log4j的输出性能问题,log4j的作者选择重新编写了一个日志门面--Slf4j,并且编写了基于Slf4j的日志实现--logback,其输出信息的效率远超log4j,解决了log4j遗留下的性能问题,所以在SpringBoot框架中,默认也选择了Slf4j来作为默认日志框架

slf4j的使用

现在,我们来看看slf4j的使用,引入maven依赖:

<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.28</version>
</dependency>

按照slf4j官方的说法,,日志记录方法的调用,不应该来直接调用日志的实现类,而是调用日志抽象层里面的实现方法,获取通过日志工厂创建的日志实例,即可输出对应的日志:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class HelloWorld { public static void main(String[] args) { 
 Logger logger =                            LoggerFactory.getLogger(HelloWorld.class);    logger.info("Hello World");
 }
}

这里我们注意到了一点,使用slf4j的输出日志的时候,我们也引入了logback这个基于slf4j日志门面实现的具体日志输出框架,如果不指定具体的日志输出实现,将会找不到具体的日志输出实例,slf4j的日志输出过程如图所示:

slf4j日志输出过程.png

从图中可以看到,应用程序调用了slf4j的api接口以后,具体的实现则是由slf4j日志门面找到对应的日志的系统来实现日志输出

解决多框架日志不统一问题

现在我们再回到日志统一的问题上,前面已经了解了,开发常用的框架,如Springmybatis等使用的框架都是框架开发者自己选择的,如果我们每个框架就引入一个日志系统,并且最终需要打印日志的时候,会出现使用n种日志系统平台,并且每一种的日志打印的格式、内容和性能都需要手动控制,不仅让项目变大,而且增大了项目复杂度,对性能也有很大的影响,那么我们该如何让所有的开源框架统一使用Slf4j来输出呢?我们来看下slf4j官方给我们的方案,如图所示:

sfl4j适配日志.png

从图中我们可以看出来,官方的方案是针对不同的日志框架,开发了一套适配兼容的框架与之对应,使用这些兼容jar来替代原来的日志框架即可,例如log4j日志框架,与之对应的就是log4j-over-slf4j.jar,并且常见的日志框架,slf4j团队都实现了一套与之对应的基于slf4j的兼容框架,关系如下:

日志框架 slf4j兼容框架
log4j log4j-over-slf4j
commons logging jcl-over-slf4j
java.util.logging jui-to-slf4j

SpringBoot如何处理日志关系

在使用SpringBoot的时候,我们会发现官方默认使用的是spring‐boot‐starter‐logging这个starter来引入日志系统的,我们展开该依赖的依赖图,如下:

SpringBoot处理日志关系.png

可以看到spring‐boot‐starter‐logging这个starter中,引入了四个日志实例的依赖,分别是logback和我们前面提到的日志兼容jar的依赖,并且最终引入了slf4j的日志门面的依赖,实现了统一日志处理。但是为什么兼容jar引入后就能解决日志输出的问题呢?难道兼容包有什么神奇的黑科技吗?其实不然,我们随便展开其中的几个兼容日志jar的包名,如图:


日志兼容包的包名关系.png

原来这些日志兼容包的包名与原来的日志框架的包名完全一样,并且完全按照slf4j的方式实现了一套和以前一样的API,这样依赖这些日志框架的开源框架在运行的时候查找对应包名下的class也不会报错,但熟悉java类加载机制的都知道,两个jar的包名以及使用的class都一样的话,加载会出现异常,我们进入spring‐boot‐starter‐logging的pom依赖中一探究竟,最后在maven依赖中发现了端倪,如Spring框架使用的是commons-logging,而在spring-boot-starter-logging中,将spring的日志依赖排除,如下:

<dependency>        
    <groupId>org.springframework</groupId>            
    <artifactId>spring‐core</artifactId>            
    <exclusions>            
        <exclusion>                
        <groupId>commons‐logging</groupId>            
        <artifactId>commons‐logging</artifactId>     
        </exclusion>                
    </exclusions>            
</dependency> 

这样spring框架在运行时使用的时候,使用的就是兼容jar中的日志实例了,SpringBoot成功的完成了一次日志系统统一的偷天换日操作。

slf4j的桥接原理

通过查看SpringBoot的日志处理,我们可以大致总结如下几步操作:

1、将系统中其他日志框架先排除出去;
2、用中间包来替换原有的日志框架;
3、我们导入slf4j其他的实现

通过以上的操作,即可完成日志系统的统一,但是我们开始有了新的疑惑,slf4j是怎么做到的自动查找对应的实现日志,并且完成了日志的正常打印操作的呢?这个就要涉及到slf4j的桥接原理,我们先来看看slf4j源码中关于日志调用相关的代码:

//slf4j日志调用过程相关的代码
//根据名称获取日志实例
public static Logger getLogger(String name) {
    ILoggerFactory iLoggerFactory = getILoggerFactory();
    return iLoggerFactory.getLogger(name);
}
//获取日志实例工厂并且完成日志实例的查找与初始化操作
 public static ILoggerFactory getILoggerFactory() {
    if (INITIALIZATION_STATE == UNINITIALIZED) {
      INITIALIZATION_STATE = ONGOING_INITIALIZATION;
      //查找实现类
      performInitialization();
    }
    ...
    return StaticLoggerBinder.getSingleton().getLoggerFactory();
    ...  
 }

可以看到整个过程中是通过StaticLoggerBinder.getSingleton() 来进行初始化日志工厂操作,而StaticLoggerBinder这个类是从哪来的呢?我们发现StaticLoggerBinder类并不存在于slf4j的jar中,而是通过查找org/slf4j/impl/StaticLoggerBinder.class类的路径来发现具体的实现类,代码如下:

//设置默认的查找日志实例的StaticLoggerBinder路径
private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";

private static Set findPossibleStaticLoggerBinderPathSet() {
  .......
  paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH);
  ......
}

这个时候我们就该思考一个问题,如果我们同时存在了多个StaticLoggerBinder 时会加载哪一个呢?熟悉java类加载机制可知,类加载器会按照一定的顺序逐个扫描jar包目录并且加载出来,所以先被类加载器扫描的StaticLoggerBinder会优先被加载,具体的加载顺序如下:

1.$java_home/lib 目录下的java核心api

2.$java_home/lib/ext 目录下的java扩展jar包

3.java -classpath/-Djava.class.path所指的目录下的类与jar包

4.$CATALINA_HOME/common目录下按照文件夹的顺序从上往下依次加载

5.$CATALINA_HOME/server目录下按照文件夹的顺序从上往下依次加载

6.$CATALINA_BASE/shared目录下按照文件夹的顺序从上往下依次加载

7.项目/WEB-INF/classes下的class文件

8.项目/WEB-INF/lib下的jar文件

根据slf4j桥接原理改造logger

我们都知道平时使用slf4j输出日志的时候往往获取Logger实例来进行日志打印,但是Logger仅仅支持本地日志,不支持分布式环境的日志,而在slfj中有LogBean实例,可以支持分布式日志,包含了链路相关信息,那么我们是否可以改造slf4j的桥接过程,使得我们可以灵活的使用本地日志或者分布式日志呢?首先我们先看看我们需要实现的需求:

  1. logger和logbean结合,统一日志入口
  2. logbean降低代码侵入性
  3. 无缝替换第三方框架中的日志,根据需求加入到分布式日志中

想要实现这个功能,有以下两个思路实现:

1.我们通过自定义appender,基于logback的appender进行扩展,可以实现分别输出本地日志以及分布式日志,但是缺陷在于appender扩展性不高,很多参数信息获取不到,例如上下文信息等

2.我们通过实现Logger接口,用来将Logger和LogBean聚合在一起,从而实现LogBean集成到Logger中,同样此种方式的缺陷在于对于第三方框架日志,我们无能为力,无法直接替换使用,并且在使用的时候需要使用自定义的LogFactory

第一种思路我们可以看出来,局限性太高,灵活度不够,接下来我们尝试使用第二种方案,实现聚合LoggerLogBean,对外公开统一的api进行日志输出使用:

public class CustomLogger implements LocationAwareLogger {
    private Logger logger;
    //提供getLogger方法获取logger
    public static LoggerFacade getLogger(Class clazz) {
        LoggerFacade loggerFacade = new LoggerFacade();
        loggerFacade.logger = LoggerFactory.getLogger(clazz);
        return loggerFacade;
    }
    ...
    //打印本地日志的同时 输出到logbean中
    @Override
    public void warn(String msg) {
        logger.warn(msg);
        appendExtra(msg, Level.WARN);
    }
    
    ......
    
        public void appendExtra(String str, Level level) {
        String date = DateFormatUtils.format(new Date(), "yyyy-MM-dd HH:mm:ss");
        //获取上下文,通过上下文判断,如果存在则获取分布式环境的LogBean实例
        ThreadContext threadContext = ContextContainer.retrieveServiceContext();
        if (threadContext != null) {
            LogBean logBean = threadContext.getLogBean();
            if (logBean != null) {
                logBean.getInner().getExtra().add(date + " " + level.toString() + " " + simpleName(getName()) + " -" +
                        " " + str);
            }
        }
    }
}

接下来我们可以替换slf4j的实现,修改为我们自定义的CustomerLogger,内部调用logback的日志本地输出,而通过前面桥接原理可以知道,slf4j具体桥接获取实例的过程是通过LoggerFactory来获取,那么我们来尝试修改LoggerFactory的代码实现替换为CustomerLogger实例:

public class CustomLoggerFactory implements ILoggerFactory {

    private static CustomLoggerFactory customLoggerFactory;

    public static CustomLoggerFactory getInstance(LoggerContext loggerContext) {
        if (customLoggerFactory == null) {
            customLoggerFactory = new CustomLoggerFactory(loggerContext);
        }
        return customLoggerFactory;
    }
    //logback的LoggerFactory实现
    private LoggerContext loggerContext;

    public CustomLoggerFactory(LoggerContext loggerContext) {
        this.loggerContext = loggerContext;
    }
    //返回CustomLogger
    @Override
    public Logger getLogger(String name) {
        ch.qos.logback.classic.Logger logger = loggerContext.getLogger(name);
        return CustomLogger.getLogger(logger);
    }

    public LoggerContext getLoggerContext() {
        return loggerContext;
    }
    
    @Override
    public ILoggerFactory getLoggerFactory() {
        if (!initialized) {
            return defaultLoggerContext;
        }

        if (contextSelectorBinder.getContextSelector() == null) {
            throw new IllegalStateException(
                    "contextSelector cannot be null. See also " + NULL_CS_URL);
        }
        LoggerContext loggerContext = contextSelectorBinder.getContextSelector().getLoggerContext();
        return CustomLoggerFactory.getInstance(loggerContext);
    }
}

由以上替换后,项目中通过LoggerFactory获取的到logger对象 就替换成了CustomLogger对象了,从而实现了降低侵入,将LoggerLogBean整合的效果

推荐阅读更多精彩内容

  • log4j, log4j2, slf4j, logback关系 log4j是由Apache开发的一套元老级日志框架...
    rainybowe阅读 502评论 1 4
  • java各日志组件介绍 common-logging(同时也称JCL)   common-logging是 apa...
    良辰美景TT阅读 708评论 0 2
  • 在项目开发过程中,我们可以通过 debug 查找问题。而在线上环境我们查找问题只能通过打印日志的方式查找问题。因此...
    Java架构阅读 1,899评论 2 37
  • 概述 在项目开发中,为了跟踪代码的运行情况,常常要使用日志来记录信息。在Java世界,有很多的日志工具库来实现日志...
    静默虚空阅读 1,113评论 1 8
  • 最近,新开发的一个项目遇到了一个log4j的配置问题,之前一直没怎么关注过日志框架,借助这个机会,好好了解下Jav...
    漂泊的胡萝卜阅读 823评论 1 22