Dynamic adjustment of log level ideas & implementation

introduction

In the previous article, Performance Tuning - Small Log and Big Pit has been introduced in detail under high concurrency. Improper use of log posture may lead to a sharp drop in service performance. The end of the article also leaves you with a solution - dynamic adjustment of the log level.
This article will introduce the implementation principle and source code of "Dynamic Log" in detail. I hope you can "handy" in dealing with log problems in the future production environment!

background

The importance of logs is self-evident. It is one of the important means for us to troubleshoot problems and solve bugs. However, in a high-concurrency environment, there will be paradoxes:
A large number of logs are printed, which consumes I/O, resulting in high CPU usage; reducing logs, the performance is down, but the link for troubleshooting is broken.

Pain point: On the one hand, we need to use logs to quickly troubleshoot problems, and on the other hand, we need to take into account performance. Can the two be combined?
Then the dynamic log adjustment implementation in this article is conceived and developed to solve this pain point.

Features

• Low intrusion, fast access : intervene in the form of a second-party package (jar), only need to configure and enable, no sense of business
• Respond in time and make changes as you adjust : In response to R&D accidentally printing a large number of INFO logs on the ingress link with large traffic, the log level can be adjusted in time
• Ladder configuration support : the default global setting is the bottom line, and it can also support local Logger release/current limiting
• Humanized operation : with the operation interface, easy to modify

<!-- more -->

Technical realization

As follows, I will use log4j2 as an example to explain, other log implementations are similar, just refer to the implementation.
The following is an example of a configuration file for log intervention:

 <?xml version="1.0" encoding="UTF-8"?>
<configuration status="info">
<Properties>
    // 全局参数信息
</Properties>

<appenders>
    // appender 详细配置
</appenders>

<loggers>
    // 配置 appender 指向
</loggers>
</configuration>

In the past, when we adjusted the log of the project, we either deleted the waste log in the code, or modified the xml configuration above, set the log level limit for a certain package or class, and then repackaged and deployed it to take effect. The efficiency at this time is very low and does not meet our demands.
So how to achieve dynamic adjustment, the first thing that comes to mind is how does the xml adjustment log level take effect? The xml itself is some configuration information. The implementation class of log reads the xml information and dynamically modifies the log level. Is it possible that we directly call the encapsulation method inside log4j in the program and bypass the xml?

Dynamically adjust the log level

Source code viewing: I have put the detailed source code on github dynamic-logger-util , you can view it yourself.

Following the idea, after viewing the log4j source code, it is found that it is indeed feasible. The following is the implementation code of the adjustment log method:

 // 获取日志上下文
LoggerContext logContext = LoggerContext.getContext(false);
Configuration configuration = logContext.getConfiguration();
LoggerConfig loggerConfig = configuration.getRootLogger();
loggerConfig.setLevel(level);

// 生效
logContext.updateLoggers();

After obtaining the current LoggerContext, then obtain the configuration, the current configuration is converted from the configuration in the xml, and then obtain the root logger, that is, the configuration in the corresponding xml is as follows:

 <Root level="info">
    <AppenderRef ref="..."/>
    <AppenderRef ref="..."/>
</Root>

Where level is the log level we need to change, the available log levels are as follows (refer to org.apache.logging.log4j.Level):

 OFF, FATAL, ERROR, WARN, INFO, DEBUG, TRACE, ALL;

As above, we can already change the global log level, so for example, how can I change the log level within a certain class ?

 LoggerContext logContext = LoggerContext.getContext(false);
if (logContext.hasLogger(name)) {
    // 精确匹配
    Logger logger = logContext.getLogger(name);
    logger.setLevel(newLevel);
    flag = true;
} else {
    // 正则匹配
    Collection<Logger> loggers = logContext.getLoggers();
    for (Logger logger : loggers) {
        if (Pattern.matches(name, logger.getName())) {
            logger.setLevel(newLevel);
            flag = true;
        }
    }
}

The log level corresponding to the current class can be set by obtaining the corresponding logger through the obtained logContext. The corresponding program code is as follows:

 // name = com.jifuwei.dynamic.logger.DynamicLoggerConfiguration
private static final org.slf4j.Logger  = LoggerFactory.getLogger(DynamicLoggerConfiguration.class);

As above, you already know how to dynamically modify the log api, so how to dynamically trigger the modification?

Configure trigger

There are many mechanisms for triggering updates. We sort them out as follows:

As mentioned above, the simplest and most convenient is the configuration center, which is now all micro-services. Most of them use the central configuration to notify each system of information changes. The configuration center has a complete interface and functions, which can meet our needs. Real-time change notification, and grayscale deployment, reducing errors, is simply the best partner for dynamic configuration.

There are many options in the configuration center. I will use Apollo as an example to demonstrate how to trigger log level changes. I will configure the Key design as follows:

 // 全局控制日志级别
key: log_level val=OFF/FATAL/ERROR/WARN/INFO/DEBUG/TRACE/ALL

// 局部控制日志级别
key: log_level_detail

val:
{
    "com.jifuwei.demo.Test1": "ERROR", // 每个 logger 都可配置自己专属的日志级别
    "com.jifuwei.demo.Test2": "OFF",
    "com.jifuwei.demo.Test3": "INFO",
}

The key implementation is as follows:

 public void init() {
    // 初始化风控监听action配置
    String level = apolloConfig.getProperty(LOGGER_LEVEL, Level.ERROR.name());
    setRootLoggerLevel(Level.valueOf(level));

    // 注册监听
    apolloConfig.addChangeListener(this);
}

public void onChange(ConfigChangeEvent changeEvent) {
    if (changeEvent.changedKeys().contains(LOGGER_LEVEL)) {
        String newValue = changeEvent.getChange(LOGGER_LEVEL).getNewValue();
        try {
            setRootLoggerLevel(Level.valueOf(newValue));
        } catch (Exception e) {
            log.error("loggerLevel onChange error", e);
        }
    }
    if (changeEvent.changedKeys().contains(LOGGER_LEVEL_DETAIL)) {
        String newValue = changeEvent.getChange(LOGGER_LEVEL_DETAIL).getNewValue();
        try {
            parseLoggerConfig(newValue);
        } catch (Exception e) {
            log.error("loggerLevel detail onChange error", e);
        }
    }
}

During initialization, the current global log level and local log level are obtained from apollo config, and then the listener is registered. At this time, it is only necessary to set the above key in the apollo configuration interface, and the program will immediately receive the update and reset the corresponding log level.

All the source code of this article is placed in the github repository: https://github.com/jifuwei/dynamic-logger-util , you can view/request/use it at any time, and ask questions at any time.

Summarize

Modify the log level through xml to trace the api method, find the available method, and then design how to trigger the method call. According to this idea, the problem of dynamically adjusting the log level is solved. When a large number of exceptions occur in production, the logs can be downgraded, so that the I/O increase will not cause the CPU to be full, which will cause the user experience to freeze.

If you think the content I share is "dry" enough, please like, follow, and forward it. This is the greatest encouragement to me. Thank you for your support!
I hope the articles I share can be helpful to every reader!

Wonderful past

• Performance tuning - a small log is a big pit
• Performance Optimization Essentials - Flame Graph
• Flink implements real-time features in risk control scenarios

Welcome to the official account: Gugu Chicken Technical Column Personal technical blog: https://jifuwei.github.io/