当前位置: 首页 > Java > 正文

http请求返回499的case排查(一)

1 星2 星3 星4 星5 星 (2 次投票, 评分: 5.00, 总分: 5)
Loading ... Loading ...
baidu_share

前天的时候碰到了这个超级诡异的case,现象是在本机curl一个本机的静态页面,nginx返回499,google了下知道499的原因通常是服务端处理时间过长,导致客户端关闭了连接造成的,因此问题的核心就是要排查为什么服务端处理时间过长。

curl访问的静态页面是从nginx代理访问到jboss的,于是直接改为用jboss的端口去curl那个静态页面,仍然是非常的慢,因此看起来问题出在了jboss端的处理。

要看为什么处理时间过长,主要就看java进程在做什么,于是jstack看了下线程都在做什么,jstack后看到了所有的jboss处理线程全部都被占满了,这显然是导致为什么curl一个静态页面都那么慢的原因。

继续看看为什么处理线程全被占满了,从堆栈信息来看,所有的线程几乎都在同一个步骤,诡异的是线程的信息状态,我第一次看到这样的线程信息:

1
2
“http-0.0.0.0-7001-228″ daemon prio=10 tid=0x00007f7b9a1d0000 nid=0xae5c in Object.wait() [0x00000000619ec000]
java.lang.Thread.State: RUNNABLE

这个线程信息的诡异就在于动作是在Object.wait,但Thread的state却是Runnable….

先不管这个,继续根据堆栈执行到的那一行代码去排查,当时猜测的是八成是死循环之类的造成的,不过cpu消耗不高,因此也不太像,反编译代码后看到确实不可能是死循环,因为那行代码对应的就是类似这样的一个调用:
Object result = FinalClass.staticMethod(xxx);
这就相当诡异了,看起来无论如何都不应该停在这一步,要停也应该停在staticMethod里面的堆栈…

于是瞎蒙,继续用pstack来查查,pstack后看到对应的这些线程是停在了以下的步骤:

1
2
3
4
5
6
7
8
9
10
Thread 306 (Thread 0x4fada940 (LWP 69941)):
#0 0x0000003d6640af59 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00007f234fb3138b in os::PlatformEvent::park() () from libjvm.so
#2 0x00007f234fb0ffc5 in ObjectMonitor::wait(long, bool, Thread*) () from libjvm.so
#3 0x00007f234fa748eb in ObjectSynchronizer::waitUninterruptibly(Handle, long, Thread*) () from libjvm.so
#4 0x00007f234fa4ce66 in instanceKlass::initialize(Thread*) () from libjvm.so
#5 0x00007f234fba30a7 in LinkResolver::resolve_static_call(CallInfo&, KlassHandle&, symbolHandle, symbolHandle, KlassHandle, bool,
bool, Thread*) () from libjvm.so
#6 0x00007f234fa3da96 in LinkResolver::resolve_invokestatic(CallInfo&, constantPoolHandle, int, Thread*) () from libjvm.so
#7 0x00007f234fa3c514 in InterpreterRuntime::resolve_invoke(JavaThread*, Bytecodes::Code) () from libjvm.so

看到这个就可以解释为什么之前线程上的信息是in Object.wait,至于为什么jstack上看到Thread的State是Runnable,原因是那里是根据java stack来看的,看不到native stack上的状况(在比较高的一些jdk版本上可通过执行jstack -m直接将java stack和native stack一起打印出来,那样会方便很多),否则的话只能自己通过pstack + jstack,并结合线程id这个来做对应关系。

从pstack的堆栈,可以解释为什么java stack停在了FinalClass.staticMethod那行,因为这个时候才刚开始初始化这个static类,多个线程初始化static类时,只有一个会执行,其他的都会在等待中,但这里没法解释的是为什么一直在wait….

后来就这个问题求助了下@rednaxelafx ,因为没有现场了,猜测可能是classloader的deadlock bug,具体见rednaxelafx写的这个case。

从这个case描述来看,只有jdk 7/+才彻底解决了这个问题。

关于这个case的排查,只能说目前猜测是这样的,因为现在没法重现,所以也不能完全确认,rednaxelafx给我对这个case如果重现的排查的建议值得学习,就是如重现,可以先做下core dump,这样之后定位就会很好做了。
如果是class loader deadlock的bug,那就不太好解决了,基本上只能自己强行先做上面提到的FinalClass的装载,避免掉多线程同时来做这件事时的竞争问题。

ps: 最近又碰到了两起并发场景下错误使用HashMap导致的cpu耗光的case,其中一个case中代码是这样写的:

1
2
3
4
5
6
7
8
9
10
11
if (this.newCacheMap.get(key) == null) {
this.newCacheMap.put(key, Integer.valueOf(1));
return null;
}
// do sth through rpc…
怎么改比较合适呢,我的建议是将newCacheMap换为ConcurrentHashMap,然后把代码修改为:
if (this.newCacheMap.get(key) == null) {
if(this.newCacheMap.putIfAbsent(key, Integer.valueOf(1)) == null){
return null;
}
}

本文固定链接: http://www.chepoo.com/http-return-499-case-one.html | IT技术精华网

http请求返回499的case排查(一):等您坐沙发呢!

发表评论