Thoroughly resolve log conflicts in SLF4J

Today, when my colleagues came online, they found that some machines printed logs, while others did not type a log. It used to be OK.

So guess is that this development indirectly introduced a new log jar package, and log conflicts resulted in unprinting.

Scanning the code found that the system was using the SLF4J framework to print log4j2 logs. Looking at the jar packages introduced in the system, we found that there are actually multiple SLF4J bridging packages. This eliminates the conflicting jar packages, and all machines print the logs when they go online


Previous diagram: the SLF4J framework, diagrams of specific log implementations, and corresponding bridging packages

1. Causes

Because online systems access many middleware, there are various forms of log printing in the system (for example, log4j2, JCL, logback, and so on).

In order to integrate all logs and print them uniformly, the SLF4J framework is most commonly used.

As a facade framework, the SLF4J framework has no specific implementation of the log. Instead, associate transformations with other specific log implementations and configure a log implementation in the system for printing.

This makes it easy to introduce conflicts with jar packages, resulting in multiple log implementations. When the log implementation chosen by the SLF4J framework is inconsistent with our configuration, the log will not print.

The SLF4J framework prints prompts when it finds multiple log implementations. But because it's standard error output, it prints in the console (Tomcat's catalina.out) [When there's no log printing in the business log file, you can check if catalina.out has prompts]



2. Why only some machines print

Because each SLF4J bridge package has org.slf4j.impl.StaticLoggerBinder

SLF4J randomly selects one to use. You can print the log when you choose the same one as your system configuration, otherwise you won't be able to print it.


3. Quickly perceive multiple SLF4J bridging packages

The findPossibleStaticLoggerBinderPathSet method, shown above, returns a Set collection and prompts for a message when there are multiple log bridge packages.

Because this message is not strong enough to be perceived. From this point, we can use reflection to get the actual number of bridging packages in the system and give custom hints.

1. Implement the BeanFactoryPostProcessor for spring and leave it under the management of spring. Ensure automatic log conflict checking after system boot

2. Use reflection to get an instance of LoggerFactory and the return result of the findPossibleStaticLoggerBinderPathSet method

3. Make a custom alarm based on the number of bridging packages

4. Arrange packages according to alarm information


<bean class="LogJarConflictCheck" />

/**
 * Log jar package conflict checking
 */
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");
            // Forced Entry
            method.setAccessible(true);
            Set<URL> staticLoggerBinderPathSet = (Set<URL>)method.invoke(instance);
            if (CollectionUtils.isEmpty(staticLoggerBinderPathSet)) {
                handleLogJarConflict(staticLoggerBinderPathSet, "Class path is Empty.Add corresponding log jar package");
            }
            if (staticLoggerBinderPathSet.size() == 1) {
                return;
            }
            handleLogJarConflict(staticLoggerBinderPathSet, "Class path contains multiple SLF4J bindings. Pack attention");
        } catch (Throwable t) {
            t.getStackTrace();
        }
    }
    /**
     * Log jar package conflict alert
     * @param staticLoggerBinderPathSet jar package path
     * @param tip Prompt
     */
    private void handleLogJarConflict (Set<URL> staticLoggerBinderPathSet, String tip) {
        String ip = getLocalHostIp();
        StringBuilder detail = new StringBuilder();
        detail.append("ip by").append(ip).append("; The prompt is").append(tip);
        if (CollectionUtils.isNotEmpty(staticLoggerBinderPathSet)) {
            String path = JsonUtils.toJson(staticLoggerBinderPathSet);
            detail.append("; Duplicate package paths are ").append(path);
        }
        String logDetail = detail.toString();
        
        //TODO uses custom alerts to notify logDetail information
    }

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

}

4. One-time configuration, lifelong reliability

The above method only helps us to quickly detect log jar package conflicts, which still need to be manually scheduled.

Is there a solution that can help us solve this problem thoroughly?

The answer is yes
Declare the jar packages we need to import and the jar packages that need to be excluded to the top level of maven. Declare the excluded packages as provided s

This scenario utilizes maven's sweeping strategy:

1. Depending on the principle of shortest path priority;

2. Declare the priority principle when the dependent paths are the same

When we declare all jar packages as direct dependencies, they are used first.
The packages we need to exclude will not be included as long as they are declared provided.
This allows the packages we need to be implemented as declared, and the packages that need to be excluded will not be affected by indirect dependencies

<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>
    <!--System usage log4j2 Implement as System Log slf4J As a facade -->
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>${slf4j.version}</version>
    </dependency>

    <!--Use log4j2 As an actual log implementation-->
    <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>

    <!--take log4j,logback,JCL Of jar Package set to provided,Not in the bag-->
    <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>


    <!--To prevent circular switching, exclude log4j2 turn slf4j Bridge package for-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-to-slf4j</artifactId>
        <version>${log4j2.version}</version>
        <scope>provided</scope>
    </dependency>

    <!--statement log4j,JCL,JUL turn slf4j Bridge package for which the corresponding log in the code can be converted to 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>

    <!--statement slf4j turn SLF4J Bridge package for-->
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <version>${log4j2.version}</version>
    </dependency>

    <!--Exclude slf4j turn log4j,JCL,JUL turn slf4j Bridge package for bridging package to prevent log implementation jar packet collisions-->
    <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>

summary

Scenario for Step 3: Perception of log jar package conflicts at startup and manual scheduling after conflicts

The fourth step is to declare all the log jar package configurations required at once without worrying about conflicts


------The End------




If this works for you, or if you want to keep an eye on it, you can also scan the QR code below or search the WeChat Public Number for "No End"


Posted on Thu, 04 Nov 2021 18:08:46 -0400 by andrew_U