当前位置: 移动技术网 > IT编程>开发语言>Java > 有趣的bug——Java静态变量的循环依赖

有趣的bug——Java静态变量的循环依赖

2019年11月14日  | 移动技术网IT编程  | 我要评论

云企招聘,置之不理造句,蔡妍不带罩的照片

背景

是的,标题没有错误,不是spring bean的循环依赖,而是静态变量之间的循环依赖。
近期的项目均是简单的maven项目,通过k8s部署在阿里云上,其配置文件读取规则如下所示:

(1) 优先读取应用部署同层目录下的配置文件;

(2) 如果没有外部配置文件,则读取打包至jar包中的配置文件。

在部署的过程中,发现应用无法争取读取外部配置文件中的配置信息,坚持不懈的读取打包文件中的。

日志文件配置错误

<?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"
                        }'/>
    
    <!--输出到控制台-->
    <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>

截取部分日志配置,日志格式定义为json格式,其中system,level以及platform参数是在程序运行时进行获取的(通过logback.xml文件中定义的${application.system},${application.region},${application.platform},这几个参数后面定义了相关的类,应用在写日志时会调用相关类接口获取对应参数信息)。但是此时遇到问题,无论如何修改外部配置文件,日志均是读取jar包中配置文件信息,在com.eqos.network.config.logsystemparamdefiner类中打断点,发现程序未进入此类获取system信息。以下是application.properties文件中的配置信息。

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

生成日志信息如下所示:

{"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}}"}

简单对照一下配置文件,就会发现日志中使用${application.system},这与配置文件中的配置key值重名,会不会是日志程序在无法通过接口获取应用配置信息后,直接从jar包内的配置文件中读取同名配置属性。针对此,修改logback.xml中的相关配置,如下所示:

    <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"
                        }'/>

修改如上所示,去除application前缀,重新启动程序:

{"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}}"}

美妙的事情发生了,去除了前缀后,日志应用就无法从jar包内的配置文件读取同名的属性信息了,日志中的system显示为system_is_undefined,此处带上了_is_undefined后缀,表明日志应用无法获取此属性对应的具体数值。
进一步检查日志配置文件,发现从配置文件读取属性是因为配置了以下属性:<property resource="application.properties"/>
后续的问题就集中于,为什么日志应用无法读取com.eqos.network.config.logsystemparamdefiner通过接口提供的属性信息呢?

静态变量循环依赖

抽丝剥茧

以下为com.eqos.network.config.logsystemparamdefiner的相关代码,其继承于logabck提供的propertydefinerbase抽象类,当应用启动时,logback就会调用实现此抽象类的对象,获取属性的具体数值。

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() {
        // 读取配置文件中属性,相关代码非重点,因此省略
        initapplicationconfig();
    }

    public concurrenthashmap<string, string> getconfiginfomap() {
        return configinfomap;
    }
}

由以上代码可以看出,logsystemparamdefiner类较为简单,其依赖于appconfig类的单例对象。appconfig类也很简单,通过静态变量实现单例(当前应用程序就不考虑反射或者序列化破坏单例了)。那就只能打断点跟进,看看究竟是什么原因 导致无法读取system属性,按理说此处就算无法正确读取到system属性值,也会使用unknown值进行替代。
打断点进入程序,发现在启动阶段进入logsystemparamdefiner.getpropertyvalue方法,尴尬的事情发生了,此时appconfig.instance为null(是的,java中的绝大多数问题都是npe,此处就不计较为什么npe被吞了)。这是为什么呢,按理说静态单例里应该在appconfig类进行加载的时候,就创建相应的静态变量对象,不应该为空。

探寻究竟

现在问题很简单,就是为什么appconfig的单例类初始化失败呢?通过有限的编程经验来说,应该是发生循环依赖了,而且这个循环依赖必然是发生在日志单例和appconfig单例之间(logback的实现肯定是单例,我想不到它不是单例的理由)。
检查appconfig代码,其实主要就是检查import引入的依赖项,代码如下所示:

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;

问题已很明显了,只有slf4j与日志相关,应该就是它引入了对logback单例的依赖。检查appconfig代码,发现虽然未使用到日志类,但是在类上存在@slf4j注解。现在去除@slf4j注解,再次进行试验发现,代码再次进入logsystemparamdefiner.getpropertyvalue方法时,appconfig.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);
    }
}

讲原理大家可能不太容易理解,此处就通过stackoverflow上的例子进行讲解。这个代码如果写在实际的工程中,可能会被打的很惨(是的,前面的问题确实很愚蠢),不过很容易看出来类a与类b中的静态变量存在循环依赖。

以下讲解此程序的执行顺序:

(1) 主线程执行main函数吗,class loader加载类b;

(2) 加载类b时,初始化静态变量b.y;

(3) b.y依赖于a.x,因此class loader加载类a;

(4) 加载类b时,初始化静态变量a.x,a.x依赖于b.y;

(5) 此时b尚未加载完全,因此b.y数值为0(如果b.y为object,则对应数值为null),所以a.x数值为1;

(6) 返回类b继续执行b.y的初始化操作,因为a.x=1,因此b.y数值为2;

(7) 类a与类b的初始化完成,a.x=1,b.y=2。

以上代码能够得到具体数值,这是因为java对于基本类型以及对象类型均会赋予初始化数值。如果换成c++,在ub的指引下,会出现什么那就真的不得而知了。

ps:
如果您觉得我的文章对您有帮助,请关注我的微信公众号,谢谢!
程序员打怪之路

如对本文有疑问,请在下面进行留言讨论,广大热心网友会与你互动!! 点击进行留言回复

相关文章:

验证码:
移动技术网