background

Yes, the title is correct, not Spring Bean's circular dependency, but the circular dependency between static variables.
Recent projects are simple Maven projects, deployed on the Ali Cloud through K8S, with configuration file reading rules as follows:

(1) Priority is given to reading the configuration files in the same directory of the application deployment;

(2) If there is no external configuration file, read the configuration file packaged in the jar package.

During the deployment process, it was found that the application could not strive to read the configuration information in the external configuration file and relentlessly read from the packaged file.

Log file configuration error

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">
    <contextName>external-portal-inspector</contextName>
    <property name="LOG_PATH" value="./logs"/>
    <property resource="application.properties"/>
    <define name="application.system" class="com.eqos.network.config.LogSystemParamDefiner"/>
    <define name="application.region" class="com.eqos.network.config.LogRegionParamDefiner"/>
    <define name="application.platform" class="com.eqos.network.config.LogPlatformParamDefiner"/>
    <property name="log.pattern" value='{
                        "date":"%date{\\\"yyyy-MM-dd HH:mm:ss.SSS\\\",UTC}",
                        "level":"%level",
                        "system":"${application.system}",
                        "platform":"${application.platform}",
                        "region":"${application.region}",
                        "filepath":"%class:%line",
                        "msg":"%msg"
                        }'/>
    
    <!--Output to console-->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>
                DEBUG
            </level>
        </filter>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers class="net.logstash.logback.composite.loggingevent.LoggingEventJsonProviders">
                <pattern>
                    <pattern>
                        ${log.pattern}
                    </pattern>
                </pattern>
            </providers>
            <charset>UTF-8</charset>
        </encoder>
    </appender>
</configuration>

Intercept part of the log configuration, the log format is defined as json format, where system,level, and platform parameters are obtained at the run-time of the program (defined by the logback.xml file ${application.system},${application.region},${application.platform}. These parameters are followed by related classes, which are called by the related class interface to get the corresponding parameters when the log is written.Information).However, there is a problem at this point. Regardless of how you modify the external configuration file, the log reads the configuration file information in the Jar package, breaks points in the com.eqos.network.config.LogSystemParamDefiner class, and finds that the program did not enter this class to get the system information.The following is the configuration information in the application.properties file.

application.platform=chongqing
application.region=HUADONG
application.system=network

The generated log information is as follows:

{"date":"2019-11-14 01:48:42.695","level":"INFO","system":"network","platform":"chongqing","region":"HUADONG","filepath":"com.eqos.network.service.TcpProbeService$1$1:78","msg":"{\"tags\":{\"namespace\":\"oneNet.service.TCP.echo\",\"metric.time-delay\":24,\"metric.correct\":true}}"}

A simple comparison of the configuration files reveals that ${application.system} is used in the log, which duplicates the configuration key value in the configuration file. Does it mean that the logger reads the configuration properties with the same name directly from the configuration file in the Jar package after it cannot obtain the application configuration information through the interface?For this reason, modify the configuration in logback.xml as follows:

    <define name="system" class="com.eqos.network.config.LogSystemParamDefiner"/>
    <define name="region" class="com.eqos.network.config.LogRegionParamDefiner"/>
    <define name="platform" class="com.eqos.network.config.LogPlatformParamDefiner"/>
    <property name="log.pattern" value='{
                        "date":"%date{\\\"yyyy-MM-dd HH:mm:ss.SSS\\\",UTC}",
                        "level":"%level",
                        "system":"${system}",
                        "platform":"${platform}",
                        "region":"${region}",
                        "filepath":"%class:%line",
                        "msg":"%msg"
                        }'/>

Modify as shown above, remove the application prefix, and restart the program:

{"date":"2019-11-14 01:54:24.486","level":"INFO","system":"system_IS_UNDEFINED","platform":"platform_IS_UNDEFINED","region":"region_IS_UNDEFINED","filepath":"com.eqos.network.service.TcpProbeService$1$1:78","msg":"{\"tags\":{\"namespace\":\"oneNet.service.TCP.echo\",\"metric.time-delay\":33,\"metric.correct\":true}}"}
{"date":"2019-11-14 01:54:24.546","level":"INFO","system":"system_IS_UNDEFINED","platform":"platform_IS_UNDEFINED","region":"region_IS_UNDEFINED","filepath":"com.eqos.network.service.UdpProbeService$1:87","msg":"{\"tags\":{\"namespace\":\"oneNet.service.UDP.echo\",\"metric.time-delay\":5,\"metric.correct\":true}}"}

It's a nice thing to see that once you remove the prefix, the log application can't read the attribute information with the same name from the configuration file in the Jar package. The system in the log appears as system_IS_UNDEFINED, with the _IS_UNDEFINED suffix, indicating that the log application can't get the exact value of this attribute.
Further inspection of the log configuration file revealed that the attributes were read from the configuration file because the following attributes were configured: <property resource="application.properties"/>.
Subsequent questions focus on why log applications cannot read the attribute information provided through the interface by com.eqos.network.config.LogSystemParamDefiner?

Static variable cyclic dependency

Reel silk from cocoons -- make a painstaking investigation

The following is the code for com.eqos.network.config.LogSystemParamDefiner, which inherits from the PropertyDefinerBase abstract class provided by logabck. When the application starts, logback calls the object that implements the abstract class to get the specific value of the property.

public class LogSystemParamDefiner extends PropertyDefinerBase {

    @Override
    public String getPropertyValue() {
        return AppConfig.INSTANCE.getConfigInfoMap().getOrDefault("application.system", "UNKNOWN");
    }
}

@Slf4j
public class AppConfig {

    public static final AppConfig INSTANCE = new AppConfig();

    private final ConcurrentHashMap<String, String> configInfoMap = new ConcurrentHashMap<>(16);

    private AppConfig() {
        // Read properties in configuration file, relevant code is not important, so omit
        initApplicationConfig();
    }

    public ConcurrentHashMap<String, String> getConfigInfoMap() {
        return configInfoMap;
    }
}

As you can see from the code above, the LogSystemParamDefiner class is simpler and relies on a single object of the AppConfig class.The AppConfig class is also simple and implements singletons through static variables (the current application does not consider reflection or serialization destroying singletons).You can only interrupt point follow-up to see what causes the system attribute to be unreadable and, arguably, use the UNKNOWN value instead, even if the system attribute value cannot be read correctly here.
The interruption point enters the program and finds that the embarrassing thing happens when it enters the LogSystemParamDefiner.getPropertyValue method during startup, when AppConfig.INSTANCE is null (yes, most of the problems in java are NPEs, and no NPEs are swallowed here).This is why, in a static singleton, it is reasonable to create a corresponding static variable object when the AppConfig class is loaded, and it should not be empty.

Explore the Real

Now the question is simple, why did AppConfig's instance class initialization fail?With limited programming experience, circular dependency should have occurred, and it must have occurred between log and AppConfig singletons (logback implementations are certainly singletons, and I can't imagine why it's not).
Check the AppConfig code, which essentially checks for dependencies introduced by import, as follows:

import lombok.extern.slf4j.Slf4j;

import java.io.File;
import java.io.FileInputStream;
import java.io.IOException;
import java.io.InputStream;
import java.util.Properties;
import java.util.concurrent.ConcurrentHashMap;

The problem is obvious, only Slf4j is log related, which should be the introduction of a dependency on logback singletons.Examining the AppConfig code, we found that although the log class is not used, there is a @Slf4j annotation on the class.Now remove the @Slf4j comment and experiment again to find that AppConfig.INSTANCE has finished initializing when the code enters the LogSystemParamDefiner.getPropertyValue method again, and the output log loads information about the external configuration file normally.

For instance

class A
{
    public static int X;
    static { X = B.Y + 1;}
}
public class B
{
    public static int Y = A.X + 1;
    static {}
    public static void main(String[] args) {
        System.out.println("X = "+A.X+", Y = "+B.Y);
    }
}

The rationale may not be easy to understand, so here's an example from stackoverflow.Writing this code in a real project can be miserable (yes, the previous question is really foolish), but it is easy to see that there is a circular dependency between static variables in classes A and B.

The following explains the order in which this program is executed:

(1) Does the main thread execute the main function, class loader loads class B;

(2) When class B is loaded, the static variable B.Y is initialized;

(3) B.Y depends on A.X, so class loader loads class A;

(4) When class B is loaded, the static variable A.X is initialized, and A.X depends on B.Y;

(5) At this time, B is not fully loaded, so the B.Y value is 0 (if B.Y is Object, the corresponding value is null), so the A.X value is 1;

(6) Return class B proceeds with the initialization of B.Y because A.X=1, so the B.Y value is 2;

(7) Initialization of class A and class B is complete, A.X=1, B.Y=2.

The above code gives you a specific value because java assigns initialization values to both the base type and the object type.If you switch to C++, what happens under the guidance of UB is really unknown.