xiaocainiaoya's blog

日常积累

0%

spring日志系统

发表于 更新于 分类于

spring日志系统

​ spring通过门面模式来应对项目中依赖不同的组件时，各组件使用不同的日志框架，有log4j、log4j2、lockback等，门面有sl4j和commons-logging。

.png

在开发的过程中，经常需要使用到日志框架来打印一些信息，来帮助开发者定位产生的相关问题等，在使用时只需要通过log.info()等方式就可以打印出一条日志信息，但是这条日志是如何打印出来，理清日志框架的工作过程及原理，能有效帮助开发者扩展日志功能以及优雅的进行日志打印等级切换等等。

springboot日志框架

springboot的默认日志框架是logback。具官网介绍logback的性能高于log4j，而log4j2是在logback之后诞生的，性能高于logback。springboot中默认引入的是logback日志框架，如果需要在springboot项目中使用sl4j2作为日志框架，需要将原生框架中的logback依赖排除。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-web</artifactId>
	<exclusions>
		<exclusion>
			<!--排除lockback的依赖-->
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-logging</artifactId>
		</exclusion>
	</exclusions>
</dependency>
<!--引入log4j2依赖-->
<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>

​ 然后就可以在resource下创建sl4j2.xml配置文件，配置一些打印相关操作，比如指定多个打印器，指定打印路径，指定打印格式、打印等级等等。当然，也可以不创建这个配置文件，在springboot有兜底配置。

​ 接着一步步来了解一下，以及springboot是如果设计，达到可以自由切换日志框架的目的。以及sl4j2的一些工作原理。

​ 如果项目中结合了lombok可以发现，在实体上标记了@Slf4j之后，就可以通过log对象来打印日志，而这个打印日志的log对象就是org.slf4j.Logger类对象，它仅仅是定义了一系列的日志打印接口。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
public interface Logger {

    public void info(String msg);

    public void info(String format, Object arg);

    public void info(String format, Object... arguments);

    public void error(String format, Object... arguments);
	
    public void error(String msg, Throwable t);
    
    // 省略代码...
}

如果工程是使用sl4j2，那么此时就会进入到org.apache.logging.slf4j.Log4jLogger，它是org.slf4j.Logger门面接口的实现，它是在依赖org.apache.logging.log4j:log4j-slf4j-impl中。

如果工程是使用logback，那么此时就会进入到ch.qos.logback.classic.Logger，它也是org.slf4j.Logger门面对象的实现，他是在依赖ch.qos.logback:logback-classis中，这里要注意，loback对门面接口类的实现的类的名称也是叫Logger。

log4j2的简单工作原理

从上述可以知道，其实打印日志都是获取Logger对象，通过它来进行日志打印操作。在log4j2中的Logger对象有两个属性PrivateConfig和LoggerContext。

  • PrivateConfig中包含了通过log4j2.xml文件解析出来的appender和具体的logger。
  • LoggerContext是根据配置规则，缓存了每个类打印时需要使用到的logger和appender的关系。

logger.png

在配置文件中的<Appenders>标签下每增加一项，解析得到的Configuration中的Appenders就多一个Appender。在<Loggers>标签下每增加一项，解析得到的Configuration中的loggerConfigs就多一项。

在LoggerConfig中持有所有Appender的引用，而解析后的Configuration中的loggerConfigs表示的是某一个logger持有的Appender引用。

如果需要使用到打印，都会先到LoggerContext的注册器LoggerRegistry中获取，如果没有，则会创建出一个Logger并注册到LoggerRegistry中。

loggerRegistry.png

比方说我这个工程中的这个类cn.com.xiaocainiaoya.common.CustomizeConfiguration，如果需要打印就会从这个注册器中获取到这个Logger，然后通过这个Logger的日志等级配置以及Appender等等进行打印操作。

Springboot日志启动机制

Springboot的日志启动依赖于springboot的事件监听机制，在spring的启动过程中，需要进行一系列的准备、加载等动作，所以Spring在对容器最终加载完成的整个生命周期中，设置了很多监听事件，比如刚刚启动容器、Enviroment准备完成、ApplicatonContext准备完成等等。日志启动是依赖于LoggingApplicationListener类，它实现了ApplicationListener的封装类GenericApplicationListener，所以它能接收到多种消息事件。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
@Override
public void onApplicationEvent(ApplicationEvent event) {
    // 在启动SpringApplicatioin之后就发布了事件，先于Environment和ApplicationContext可用之前发布
    if (event instanceof ApplicationStartingEvent) {
        onApplicationStartingEvent((ApplicationStartingEvent) event);
    }
    // Environment加载完成之后立即发布
    else if (event instanceof ApplicationEnvironmentPreparedEvent) {
        onApplicationEnvironmentPreparedEvent((ApplicationEnvironmentPreparedEvent) event);
    }
    // ApplicationContext准备好后但是刷新容器之前发布
    else if (event instanceof ApplicationPreparedEvent) {
        onApplicationPreparedEvent((ApplicationPreparedEvent) event);
    }
    else if (event instanceof ContextClosedEvent
            && ((ContextClosedEvent) event).getApplicationContext().getParent() == null) {
        onContextClosedEvent();
    }
    else if (event instanceof ApplicationFailedEvent) {
        onApplicationFailedEvent();
    }
}

1.监听到ApplicationStartingEvent事件

在Springboot中操作日志最关键的一个对象就是LoggingSystem，这个对象在整个生命周期中掌握着日志。

1
2
3
4
private void onApplicationStartingEvent(ApplicationStartingEvent event) {
    this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
    this.loggingSystem.beforeInitialize();
}

这里在接收到这个事件通知之后，就到系统属性中去读取LoggingSystem具体的实现。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
static {
    Map<String, String> systems = new LinkedHashMap<>();
    systems.put("ch.qos.logback.core.Appender", "org.springframework.boot.logging.logback.LogbackLoggingSystem");
    systems.put("org.apache.logging.log4j.core.impl.Log4jContextFactory",
            "org.springframework.boot.logging.log4j2.Log4J2LoggingSystem");
    systems.put("java.util.logging.LogManager", "org.springframework.boot.logging.java.JavaLoggingSystem");
    SYSTEMS = Collections.unmodifiableMap(systems);
}

// 首次加载的时候会从以上的SYSTEMS的map中去找，通过类加载器，逐个查找，看哪一个类是在类路径中，就启用哪一个LoggingSystem。我这里使用的是Log4j日志框架，那么这里就会找到并加载Log4J2LoggingSystem。如果使用的是logback，那么加载的就是LogbackLoggingSystem。
public static LoggingSystem get(ClassLoader classLoader) {
    String loggingSystem = System.getProperty(SYSTEM_PROPERTY);
    if (StringUtils.hasLength(loggingSystem)) {
        if (NONE.equals(loggingSystem)) {
            return new NoOpLoggingSystem();
        }
        return get(classLoader, loggingSystem);
    }
  // 通过类加载器来找有没有引入对应的类，第一个匹配到谁就是谁
    return SYSTEMS.entrySet().stream().filter((entry) -> ClassUtils.isPresent(entry.getKey(), classLoader))
            .map((entry) -> get(classLoader, entry.getValue())).findFirst()
            .orElseThrow(() -> new IllegalStateException("No suitable logging system located"));
}

拿到LogginSystem之后，就会调用它的beforeInitialize()，这个方法的主要作用就是进行一些事前初始化动作，这里添加了一个日志过滤器，但实际上是一个阻断器，这个阻断器拒绝了所有的日志打印。所以到达这一步，仍然是无法打印出日志的，就算日志框架接收到需要打印日志的请求，也会被阻断器拒绝。这样的设计是为了防止日志系统在完成初始化之前打印出不可控的日志信息。

1
2
3
4
5
6
7
8
9
@Override
public void beforeInitialize() {
    LoggerContext loggerContext = getLoggerContext();
    if (isAlreadyInitialized(loggerContext)) {
        return;
    }
    super.beforeInitialize();
    loggerContext.getConfiguration().addFilter(FILTER);
}

2.监听到ApplicationEnvironmentPreparedEvent事件

当Environment准备完成之后，继续进行日志框架的初始化。

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
28
private void onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event) {
    if (this.loggingSystem == null) {
        this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
    }
    // 使用enviroment中配置的信息对日志框架进行初始化
    initialize(event.getEnvironment(), event.getSpringApplication().getClassLoader());
}

protected void initialize(ConfigurableEnvironment environment, ClassLoader classLoader) {
    // 把在enviroment中的配置信息读取出来，并设置到system中，比如有打印文件的路径
    // 文件大小、打印格式等等
    new LoggingSystemProperties(environment).apply();
    this.logFile = LogFile.get(environment);
    if (this.logFile != null) {
        this.logFile.applyToSystemProperties();
    }
    // 将预制的web和sql日志打印初始化LoggerGroups
    this.loggerGroups = new LoggerGroups(DEFAULT_GROUP_LOGGERS);
    // 读取系统级别的debug或者trace是否设置为true
    // 哪个类型为true就将springbootLogging的级别设置为那个
    // trace的优先级高于debug
    initializeEarlyLoggingLevel(environment);
    // 执行loggingSystem.initialize()初始化方法
    initializeSystem(environment, this.loggingSystem, this.logFile);
    // 完成日志打印组和日志打印器的级别的设置
    initializeFinalLoggingLevels(environment, this.loggingSystem);
    registerShutdownHookIfNecessary(environment, this.loggingSystem);
}

重点来看下LoggingSystem的初始化方法。

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
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
private void initializeSystem(ConfigurableEnvironment environment, LoggingSystem system, LogFile logFile) {
    LoggingInitializationContext initializationContext = new LoggingInitializationContext(environment);
    // 从系统变量中获取logging.config
    String logConfig = environment.getProperty(CONFIG_PROPERTY);
    // 如果没有就根据规则从类路径中找
    if (ignoreLogConfig(logConfig)) {
        system.initialize(initializationContext, null, logFile);
    }else{
        //如果有，就直接加载指定的文件。所以如果通过yaml直接配置，或者通过jar启动命令指定
        // 就直接走到这里
        // ... 省略代码
    }
    // ... 省略代码
}

// 到达Log4J2LoggingSystem的初始化方法
@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
    LoggerContext loggerContext = getLoggerContext();
    if (isAlreadyInitialized(loggerContext)) {
        return;
    }
    // 这里移除了前面设置的日志阻断器
    loggerContext.getConfiguration().removeFilter(FILTER);
    // 调用父类方法找到log4j2的配置文件，并进行初始化
    super.initialize(initializationContext, configLocation, logFile);
    // 标记初始化完成
    markAsInitialized(loggerContext);
}

// 父类方法最终会走到这里，按类路径查找，
private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
    // 逻辑上是要找到一个 classpath:xxxx的地址
    String config = getSelfInitializationConfig();
    if (config != null && logFile == null) {
        // 把这个配置文件中的东西解析出来为Configuration
        reinitialize(initializationContext);
        return;
    }
    if (config == null) {
        config = getSpringInitializationConfig();
    }
    if (config != null) {
        loadConfiguration(initializationContext, config, logFile);
        return;
    }
    loadDefaults(initializationContext, logFile);
}

之后就会将日志打印器logger进行分组。这样做的好处是便于管理，分组之后，如果需要对某个组改日志级别，只需要将这个组的日志级别进行修改，就不需要逐个去找打印器并进行修改。

loggerGroups.png

1
2
3
4
5
6
7
8
9
10
## 可以通过yaml进行设置
logging:
  level:
    common: debug
    user: info
  group:
    common:
      - cn.com.xiaocainiaoya.common
    user:
      - com.lee.xiaocainiaoya.user

如果设置了trace=true或者是bebud=true，那么springboot会将自己的某些类的打印开启。

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
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
private void initializeFinalLoggingLevels(ConfigurableEnvironment environment, LoggingSystem system) {
    bindLoggerGroups(environment);
    // 只要trace=true 或者是 debug=true就开启springbootlogging
    if (this.springBootLogging != null) {
        initializeLogLevel(system, this.springBootLogging);
    }
    // 设置用户自定义的打印器的日志级别
    setLogLevels(system, environment);
}

protected void initializeLogLevel(LoggingSystem system, LogLevel springBootLogging) {
    initializeSpringBootLogging(system, springBootLogging);
}

protected void initializeSpringBootLogging(LoggingSystem system, LogLevel springBootLogging) {
    BiConsumer<String, LogLevel> configurer = getLogLevelConfigurer(system);
    SPRING_BOOT_LOGGING_LOGGERS.getOrDefault(springBootLogging, Collections.emptyList())
            .forEach((name) -> configureLogLevel(name, springBootLogging, configurer));
}

static {
    MultiValueMap<LogLevel, String> loggers = new LinkedMultiValueMap<>();
    // 如果是debug就开这些
    loggers.add(LogLevel.DEBUG, "sql");
    loggers.add(LogLevel.DEBUG, "web");
    loggers.add(LogLevel.DEBUG, "org.springframework.boot");
    // 如果是trace 就开这些
    loggers.add(LogLevel.TRACE, "org.springframework");
    loggers.add(LogLevel.TRACE, "org.apache.tomcat");
    loggers.add(LogLevel.TRACE, "org.apache.catalina");
    loggers.add(LogLevel.TRACE, "org.eclipse.jetty");
    loggers.add(LogLevel.TRACE, "org.hibernate.tool.hbm2ddl");
    SPRING_BOOT_LOGGING_LOGGERS = Collections.unmodifiableMap(loggers);
}

// 能按组设置就按组设置，不能按组设置就单独设置
private void configureLogLevel(String name, LogLevel level, BiConsumer<String, LogLevel> configurer) {
    if (this.loggerGroups != null) {
        LoggerGroup group = this.loggerGroups.get(name);
        if (group != null && group.hasMembers()) {
            group.configureLogLevel(level, configurer);
            return;
        }
    }
    configurer.accept(name, level);
}

3.监听到ApplicationPreparedEvent事件

日志级别热更新

其实对应的日志框架都已经提供了对应的日志级别更新方法，只需要获取到LoggingSystem类，并调用setLogLevel方法即可。

1
loggingSystem.setLogLevel("cn.com.xiaocainiaoya.BootStrap", LogLevel.DEBUG);

这里简单分析一下过程。

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
28
29
30
31
@Override
public void setLogLevel(String loggerName, LogLevel logLevel) {
	// 转换为log4j对应的日志级别枚举类
	Level level = LEVELS.convertSystemToNative(logLevel);
	// 到Configuration中去找这个loggerName的LoggerConfig(初始化之后所有的LoggerConfig都在这里)
	LoggerConfig loggerConfig = getLoggerConfig(loggerName);
	// 如果不存在，则需要创建这个LoggerConfig，并添加到Configuration的ConcurrentMap<String, LoggerConfig> loggerConfigs中。
	if (loggerConfig == null) {
		loggerConfig = new LoggerConfig(loggerName, level, true);
		getLoggerContext().getConfiguration().addLogger(loggerName, loggerConfig);
	}
	else {
		// 如果存在，则直接更新这个loggerConfig的日志级别
		loggerConfig.setLevel(level);
	}
	// ⭐️逐个更新loagger
	getLoggerContext().updateLoggers();
}

public void updateLoggers(final Configuration config) {
    final Configuration old = this.configuration;
    // 逐个更新loagger
    for (final Logger logger : loggerRegistry.getLoggers()) {
        logger.updateConfiguration(config);
    }
    firePropertyChangeEvent(new PropertyChangeEvent(this, PROPERTY_CONFIG, old, config));
}

protected void updateConfiguration(final Configuration newConfig) {
    this.privateConfig = new PrivateConfig(newConfig, this);
}

其实我刚看到这个地方时候，我是有点困惑的，在我标记⭐️的地方。在更新完loggerConfig的的日志级别之后，尽然需要将所有的loggerRegistry都取出来进行重新创建PrivateConfig。难道不是loggerConfig的日志级别修改了之后持有这个对象的引用获取到信息也是更新之后的值。但是其实这里是有可能获取不到loggerConfig，那么就需要创建一个新的loggerConfig到Configuration池子里。根据日志名称匹配规则，新增了一个loggerConfig那么其实对缓存中的所有信息有所影响，比如某个类的全限定类名是cn.com.xiaocainiao.FeignUtil，原本它是使用名称为root的打印器，但是我调用setLogLevel("cn.com.xiaocainiao", "DEBUG")那么这时会创建一个新的打印器器，也就导致了cn.com.xiaocainiao.FeignUtil应该使用新创建的这个打印器，而不是根打印器，所以这里的将所有的logger进行了更新。

-------------本文结束感谢您的阅读-------------