日志

日志框架可以说是软件系统的标配,平时使用日志的时候多数只是了解日志配置怎么配,对于这些日志框架的不同以及他们之间的关系很少了解。Java中的日志体系可以用杂乱无章来形容,因为很多,今天就来梳理下这些日志框架到底是怎么回事。

还在为弄不清commons-logging-xx.jarlog4j-xx.jarsl4j-api-xx.jar等日志框架之间复杂的关系而感到烦恼吗?

还在为如何统一系统的日志输出而感到不知所措嘛?

您是否依然存在这样的烦恼。比如,要更改spring的日志输出为log4j 2,却不知该引哪些jar包,只知道去百度一下所谓的博客,照着人家复制,却无法弄懂其中的原理?

不要急,不要方!本文带你们弄懂其中的原理,只要你静下心看本文,你就能随心所欲更改你系统里的日志框架,统一日志输出!

Log4j

Log4j 概述

一个完整的软件,日志是必不可少的。程序从开发、测试、维护、运行等环节,都需要向控制台或文件等位置输出大量信息。这些信息的输出, 在很多时候是使用 System.out.println() 无法完成的。

日志信息根据用途与记录内容的不同,分为 调试日志、运行日志、异常日志 等。

Log4j 的全称为 Log for java,即专门用于 Java 语言的日志记录工具。

对log4j的定位

用log4j,日志管理,是为了代替 sout输出语句,减少系统资源的开销,报错CPU资源,内存资源。

架构思想有些过时了,单体应用时用一用。

到SpringBoot时学logback

Log4j 日志级别

为了方便对于日志信息的输出显示,对日志内容进行了分级管理。日志级别由高到低,共分 6 个级别:

  • fatal(致命的):非常验证的错误,一般是系统错误
  • error:错误,一般表示代码错误,比较严重
  • warn:警告,不影响程序的运行,但是可能存在风险
  • info:信息,表示一个普通的输出信息
  • debug:调试,表示程序员认为的一些调试信息
  • trace(堆栈)

为什么要对日志进行分级

无论是将日志输出到控制台,还是文件,其输出都会降低程序的运行效率。但由于调试、运行维护的需要,客户的要求等原因,需要进行必要的日志输出。这时就必须要在代码中加入日志输出语句。

这些输出语句若在程序运行时全部执行, 则势必会降低运行效率。例如, 使用 System.out.println() 将信息输出到控制台,则所有的该输出语句均将执行。会大大降低程序的执行效率。而要使其不输出,唯一的办法就是将这些输出语句逐个全部删除。这是个费时费力的过程。

将日志信息进行分级管理,便可方便的控制信息输出内容及输出位置:哪些信息需要输出,哪些信息不需要输出,只需在一个日志输出控制文件中稍加修改即可。而代码中的输出语句不用做任何修改。

从这个角度来说,代码中的日志编写,其实就是写大量的输出语句。只不过,这些输出语句比较特殊,它们具有级别,在程序运行期间不一定被执行。它们的执行是由另一个控制文件控制。

Log4j 日志输出控制文件

日志输出简介

Log4j 的日志输出控制文件,主要由三个部分构成:

  • 日志信息的输出位置:控制日志信息将要输出的位置,是控制台还是文件等。
  • 日志信息的输出格式:控制日志信息的显示格式,即以怎样的字符串形式显示。
  • 日志信息的输出级别:控制日志信息的显示内容,即显示哪些级别的日志信息。

有了日志输出控制文件,代码中只要设置好日志信息内容及其级别即可,通过控制文件便可控制这些日志信息的输出了。

日志属性配置文件

日志属性文件 log4j.properties 是专门用于控制日志输出的。其主要进行三方面控制:

  • 输出位置:控制日志将要输出的位置,是控制台还是文件等。
  • 输出布局:控制日志信息的显示形式。
  • 输出级别:控制要输出的日志级别。

日志属性文件由两个对象组成:日志附加器与根日志。

根日志,即为 Java 代码中的日志记录器,其主要由两个属性构成:日志输出级别与日志附加器。

日志附加器,则由日志输出位置定义,由其它很多属性进行修饰,如输出布局、文件位置、文件大小等。

什么是日志附加器?

所谓日志附加器,就是为日志记录器附加上很多其它设置信息。附加器的本质是一个接口,其定义语法为:log4j.appender.appenderName = 输出位置

常用的附加器实现类
  • org.apache.log4j.ConsoleAppender
  • org.apache.log4j.FileAppender
  • org.apache.log4j.RollingFileAppender
  • org.apache.log4j.DailyRollingFileAppender

常用布局类型

  • org.apache.log4j.HTMLLayout
  • org.apache.log4j.SimpleLayout
  • org.apache.log4j.PatternLayout

打印参数: Log4J 采用类似 C 语言中的 printf 函数的打印格式格式化日志信息

  • %m
  • %p
  • %r
  • %c
  • %t
  • %n
  • %d
  • %l

图解:

image-20230927191054453

第一个 Log4j 日志文件

Slf4j 简介

slf4j 的全称是 Simple Loging Facade For Java,即它仅仅是一个为 Java 程序提供日志输出的统一接口,并不是一个具体的日志实现方案,就比如 JDBC 一样,只是一种规则而已。所以单独的 slf4j 是不能工作的,必须搭配其他具体的日志实现方案,比如 apache 的 org.apache.log4j.Logger,JDK 自带的 java.util.logging.Logger 以及 log4j 等。

门面模式facader,slf4j,接口调用具体怎么实现我不管

POM

继续之前的项目,pom.xml 配置如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
<dependencies>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-context</artifactId>
        <version>4.3.17.RELEASE</version>
    </dependency>
    <dependency>
        <groupId>junit</groupId>
        <artifactId>junit</artifactId>
        <version>4.12</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-log4j12</artifactId>
        <version>1.7.25</version>
    </dependency>
</dependencies>

主要增加了 org.slf4j:slf4j-log4j12 依赖

创建 log4j.properties 配置文件

在 src/main/resources 目录下创建名为 log4j.properties 的属性配置文件

1
2
3
4
5
6
7
8
9
10
11
12
log4j.rootLogger=INFO, console, file

log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.layout=org.apache.log4j.PatternLayout
log4j.appender.console.layout.ConversionPattern=%d %p [%c] - %m%n

log4j.appender.file=org.apache.log4j.DailyRollingFileAppender
log4j.appender.file.File=logs/log.log
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.A3.MaxFileSize=1024KB
log4j.appender.A3.MaxBackupIndex=10
log4j.appender.file.layout.ConversionPattern=%d %p [%c] - %m%n

.日志配置相关说明:

  • log4j.rootLogger
  • log4j.appender.console
  • log4j.appender.console.layout
  • log4j.appender.console.layout.ConversionPattern
  • log4j.appender.file
  • log4j.appender.file.File
  • log4j.appender.file.layout
  • log4j.appender.A3.MaxFileSize
  • log4j.appender.A3.MaxBackupIndex
  • log4j.appender.file.layout.ConversionPattern

测试日志输出

创建一个测试类,并测试日志输出效果,代码如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
package com.funtl.hello.spring;

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

public class MyTest {

    public static final Logger logger = LoggerFactory.getLogger(MyTest.class);

    public static void main(String[] args) {
        logger.info("slf4j for info");
        logger.debug("slf4j for debug");
        logger.error("slf4j for error");
        logger.warn("slf4j for warn");

        String message = "Hello SLF4J";
        logger.info("slf4j message is : {}", message);
    }
}

此时控制台显示为:

1
2
3
4
2018-06-07 05:15:42,914 INFO [com.funtl.hello.spring.MyTest] - slf4j for info
2018-06-07 05:15:42,915 ERROR [com.funtl.hello.spring.MyTest] - slf4j for error
2018-06-07 05:15:42,915 WARN [com.funtl.hello.spring.MyTest] - slf4j for warn
2018-06-07 05:15:42,916 INFO [com.funtl.hello.spring.MyTest] - slf4j message is : Hello SLF4J

项目根目录下也会多出 logs/log.log 目录及文件

附:占位符说明

打日志的时候使用了 {} 占位符,这样就不会有字符串拼接操作,减少了无用 String 对象的数量,节省了内存。并且,记住,在生产最终日志信息的字符串之前,这个方法会检查一个特定的日志级别是不是打开了,这不仅降低了内存消耗而且预先降低了 CPU 去处理字符串连接命令的时间。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
public class MyTest {

    private static final Logger logger = LoggerFactory.getLogger(MyTest.class);

    public static void main(String[] args) {
//        UserService userService = new UserServiceImpl();

        ApplicationContext applicationContext = new ClassPathXmlApplicationContext("spring-context.xml");
        UserService userService = (UserService) applicationContext.getBean("userService");

        userService.sayHello();

        logger.info("info 级别的日志:打开了数据库....");
        logger.debug("调试级别的日志:list集合中有....");
        logger.warn("警告级别的日志:你不是要记日志吗,怎么没有配置日志等....");
        logger.error("错误级别的日志....");

        String message = "测试";
        String message2 = "测试2";
        // logger.info("message is :" + message); // 加号,创建对象,增加了系统的资源开销,用占位符
        logger.info("message is : {} {}",message,message2);

        // 日志中+拼接浪费资源,字符串中也一样,但是字符串中没有{}占位符,用这样的:
        System.out.println(String.format("message is : %s %s",message,message2));
        System.out.println(message.concat(message2)); // 不推荐这个,和+号拼接差不多
    }
}

日志框架发展史

早年,你工作的时候,在日志里使用了log4j框架来输出,于是你代码是这么写的

1
2
3
4
5
import org.apache.log4j.Logger;
\\省略
Logger logger = Logger.getLogger(Test.class);
logger.trace("trace");
\\省略

但是,岁月流逝,sun公司对于log4j的出现内心隐隐表示嫉妒。于是在jdk1.4版本后,增加了一个包为java.util.logging,简称为jul,用以对抗log4j。于是,你的领导要你把日志框架改为jul,这时候你只能一行行的将log4j的api改为jul的api,如下所示

1
2
3
4
5
import java.util.logging.Logger;
\\省略
Logger loggger = Logger.getLogger(Test.class.getName());
logger.finest("finest");
\\省略

可以看出,api完全是不同的。那有没有办法,将这些api抽象出接口,这样以后调用的时候,就调用这些接口就好了呢?

这个时候jcl(Jakarta Commons Logging)出现了,说jcl可能大家有点陌生,讲commons-logging-xx.jar组件,大家总有印象吧。JCL 只提供 log 接口,具体的实现则在运行时动态寻找。这样一来组件开发者只需要针对 JCL 接口开发,而调用组件的应用程序则可以在运行时搭配自己喜好的日志实践工具。JCL可以实现的集成方案如下图所示

image-20230927191113051

jcl默认的配置:如果能找到Log4j 则默认使用log4j 实现,如果没有则使用jul(jdk自带的) 实现,再没有则使用jcl内部提供的SimpleLog 实现。

于是,你在代码里变成这么写了

1
2
3
4
5
6
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
\\省略
Log log =LogFactory.getLog(Test.class);
log.trace('trace');
\\省略

至于这个Log具体的实现类,JCL会在ClassLoader中进行查找。这么做,有三个缺点,缺点一是效率较低,二是容易引发混乱,三是在使用了自定义ClassLoader的程序中,使用JCL会引发内存泄露。

于是log4j的作者觉得jcl不好用,自己又写了一个新的接口api,那么就是slf4j。关于slf4j的集成图如下所示

image-20230927191119969

如图所示,应用调了sl4j-api,即日志门面接口。日志门面接口本身通常并没有实际的日志输出能力,它底层还是需要去调用具体的日志框架API的,也就是实际上它需要跟具体的日志框架结合使用。由于具体日志框架比较多,而且互相也大都不兼容,日志门面接口要想实现与任意日志框架结合可能需要对应的桥接器,上图红框中的组件即是对应的各种桥接器!

我们在代码中需要写日志,变成下面这么写

1
2
3
4
5
6
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
//省略
Logger logger = LoggerFactory.getLogger(Test.class);
// 省略
logger.info("info");

在代码中,并不会出现具体日志框架的api。程序根据classpath中的桥接器类型,和日志框架类型,判断出logger.info应该以什么框架输出!注意了,如果classpath中不小心引了两个桥接器,那会直接报错的!

因此,在阿里的开发手册上才有这么一条

强制:应用中不可直接使用日志系统(log4j、logback)中的 API ,而应依赖使用日志框架 SLF4J 中的 API 。使用门面模式的日志框架,有利于维护和各个类的日志处理方式的统一。

ok,至此,基础知识完毕,下面是实战!

项目实战

案例一

一个项目,一个模块用log4j,另一个模块用slf4j+log4j2,如何统一输出?

其实在某些中小型公司,这种情况很常见。我曾经见过某公司的项目,因为研发不懂底层的日志原理,日志文件里头既有log4j.properties,又有log4j2.xml,各种API混用,惨不忍睹!

还有人用着jul的API,然后拿着log4j.properties,跑来问我,为什么配置不生效!简直是一言难尽!

OK,回到我们的问题,如何统一输出!OK,这里就要用上slf4j的适配器,slf4j提供了各种各样的适配器,用来将某种日志框架委托给slf4j。其最明显的集成工作方式有如下:

image-20230927191126993

进行选择填空,将我们的案例里的条件填入,显然应该选log4j-over-slf4j适配器,就变成下面这张图

image-20230927191132046

就可以实现日志统一为log4j2来输出!

ps:根据适配器工作原理的不同,被适配的日志框架并不是一定要删除!以上图为例,log4j这个日志框架删不删都可以,你只要能保证log4j的加载顺序在log4j-over-slf4j后即可。因为log4j-over-slf4j这个适配器的工作原理是,内部提供了和log4j一模一样的api接口,因此你在程序中调用log4j的api的时候,你必须想办法让其走适配器的api。如果你删了log4j这个框架,那你程序里肯定是走log4j-over-slf4j这个组件里的api。如果不删log4j,只要保证其在classpth里的顺序比log4j前即可!

案例二

如何让spring以log4j2的形式输出?

spring默认使用的是jcl输出日志,由于你此时并没有引入Log4j的日志框架,jcl会以jul做为日志框架。此时集成图如下

image-20230927191213154

而你的应用中,采用了slf4j+log4j-core,即log4j2进行日志记录,那么此时集成图如下

image-20230927191218970

那我们现在需要让spring以log4j2的形式输出?怎么办?

OK,第一种方案,走jcl-over-slf4j适配器,此时集成图就变成下面这样了

image-20230927191141001

在这种方案下,spring框架中遇到日志输出的语句,就会如上图红线流程一样,最终以log4J2的形式输出!

OK,有第二种方案么?

有,走jul-to-slf4j适配器,此时集成图如下

image-20230927191146073

ps:这种情况下,记得在代码中执行

1
2
SLF4JBridgeHandler.removeHandlersForRootLogger();
SLF4JBridgeHandler.install();

这样jul-to-slf4j适配器才能正常工作。

天啦噜!要死循环

假设,我们在应用中调用了sl4j-api,但是呢,你引了四个jar包,slf4j-api-xx.jar,slf4j-log4j12-xx.jar,log4j-xx.jar,log4j-over-slf4j-xx.jar,于是你就会出现如下尴尬的场面

image-20230927191150869

如上图所示,在这种情况下,你调用了slf4j-api,就会陷入死循环中!slf4j-api去调了slf4j-log4j12,slf4j-log4j12又去调用了log4j,log4j去调用了log4j-over-slf4j。最终,log4j-over-slf4j又调了slf4j-api,陷入死循环!