诡异的http请求返回499的case排查(终)

上篇文章中,关于http请求返回499的这个case,并没有排查到根本原因,当时猜测是classloader deadlock的bug,没想到在前几天这个问题又再次重现,这次吸取了上次的经验,不仅做了jstack,还用gcore做了core dump,在拿到了core dump的情况下,好处是即使jstack -m不work,也可以通过gdb + jstack捞出线程的java stack和native stack,于是当时的做法就是先通过core dump文件拿到了线程的完整堆栈信息(java stack & native stack),当时猜想的是既然是死锁,应该可以很容易看到。

但不幸的是,即使拿到了这个,看了很久仍然是完全没头绪,开始瞎折腾,大部分的线程都停在了类似FinalClass.staticMethod这一步,统计了下停在这步的线程数,发现是245个,而处理的线程池是250个,于是捞出了另外5个线程的信息,看看都在干什么。

这5个线程中其中有3个竟然也停在了另外一个Class的static method的调用上,而另外2个线程,一个的堆栈类似如下:
[code]
Thread 29548: (state = BLOCKED)
– C.loadConfigs() @bci=6, line=465 (Interpreted frame)
– C.() @bci=346, line=448 (Interpreted frame)
– A.() @bci=235, line=143 (Interpreted frame)
[/code]

另一个堆栈类似如下:
[code]
Thread 30132: (state = BLOCKED)
– D.getContentList() @bci=4, line=91 (Interpreted frame)
– D.initContainer() @bci=9, line=67 (Interpreted frame)
– D.() @bci=23, line=49 (Interpreted frame)
– D.() @bci=4, line=41 (Interpreted frame)
– M.() @bci=27, line=188 (Interpreted frame)
[/code]

从这个堆栈也看不出什么问题,于是决定去翻看下D和B这两个类的对应的行的动作是什么,看代码的时候发现C.loadConfigs里会去调用D的一个static final的field,而D的getContentList里面会调用C的一个static方法,代码类似如下:
[code]
public class C{
public static void getList(){

}
private static void loadConfigs(){
D.INSTANCE.list();
}
static{
loadConfigs();
}
}

public class D{
private static final D INSTANCE = new D();
private D(){
initContainer();
}
private void initContainer(){
getContentList();
}
private void getContentList(){
C.getList();
}
}
[/code]
看到这两段代码,基本可以猜测到问题所在了,脑袋里对这两段代码运行了,发现如果一个线程正执行到D的getContentList的C.getList那一行,而另外一个线程正执行到C的D.INSTANCE.list()那一行,那就deadlock了,只能说,这算是一个比较隐藏的bug,因为其锁是在static Object或Field上,而不是主动编写的并发锁等。

但为什么另外那245个线程会停在看起来和这5个线程的动作完全没关系的一步上呢,翻查那一步动作的代码,发现其堆栈类似如下:
FinalClass.
S.parse()
而对应的FinalClass的static代码里会调用C的一个static的field(并且这个field对应的是C的一个static的方法),这样就可以解释了,由于C的static陷入了deadlock,所以这245个线程也都在进入了等待。

根据上面的分析,终于彻底解决了这个case,这个case给自己的教训就是对于这样的现象要更加仔细的分析stack,这次完全是靠后面仔细的看了stack猜出的原因,这个case不好排查的原因是不像普通的deadlock问题,在jstack中都可以直接看出来,偏偏是由于static Object/Field的整个过程是有锁的,但其是在native stack上的,导致了很不好排查,再加上代码层面是绕了几圈,因此导致从jstack上很难看出关联性。

根据这个case我写了一个简单的demo,感兴趣的可以从下面的url下载:
http://hellojava.info/cases/deadlockcase/demo.zip
解压后直接执行java Main,即可看到和我的case一模一样的状况,可以体验下怎么去排查这样的case,:)

对应的源码请从这下载:
http://hellojava.info/cases/deadlockcase/demo-src.zip

最后贴一个问题吧,请问下面的代码运行时会输出什么?
[code]
public class A{
public static void main(String[] args){
System.out.println(B.NAME);
}
}

public class B{
public static final String NAME=”bluedavy”;
static{
System.out.println(“hellojava”);
}
}
[/code]

=============================
欢迎关注微信公众号:hellojavacases

关于此微信号:
分享Java问题排查的Case、Java业界的动态和新技术、Java的一些小知识点Test,以及和大家一起讨论一些Java问题或场景,这里只有Java细节的分享,没有大道理、大架构和大框架。

公众号上发布的消息都存放在http://hellojava.info上。

《诡异的http请求返回499的case排查(终)》有5个想法

发表评论

电子邮件地址不会被公开。 必填项已用*标注


*