线上遇到的一个case,应用结构是nginx----->resin---java,其中nginx做lb,resin做为java的容器。在nginx层面做http code的监控,发现有4xx比例高的的报警:
分析nginx日志,发现是由于499比例高导致
1
2
|
xxx xxxxx - [29
/Oct/2012
:04:10:03 +0800]
"GET /GetConfiguration.jsp?peer_version=2.3.0.4779&peer_id=E00B3B81B458D7D5A3C2E2BD85865354 HTTP/1.0"
499 0
"-"
"-"
"-"
"-"
xxxxx:8080
" "
-
" "
0.001"
xxxxx xxxxx - [29
/Oct/2012
:04:10:03 +0800]
"GET /GetConfiguration.jsp?peer_version=2.3.0.4779&peer_id=E00B3B81B458D7D5A3C2E2BD85865354 HTTP/1.0"
499 0
"-"
"-"
"-"
"-"
"xxxx:8080"
"-"
"0.000"
|
499一般是由于后端响应超时造成,但是这里的499响应时间都在毫秒以内,证明不是超时导致,而是后端直接不能响应抛出。对于java应用来说会有两种情况,一是线程锁导致,另一个是堆栈导致。
使用jstack打印出堆栈分析,发现有类似下面的这种线程被锁:
1
2
3
4
5
6
7
8
9
10
11
12
|
"http-0.0.0.0:8080-65096$1864960835"
daemon prio=
10
tid=
0x000000004c169800
nid=
0x4bf8
waiting
for
monitor entry [
0x0000000043e8e000
..
0x0000000043e8ed10
]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.caucho.server.log.AccessLog.log(AccessLog.java:
345
)
- waiting to lock <
0x00002aaab522a638
> (a java.lang.Object)
at com.caucho.server.webapp.WebAppFilterChain.doFilter(WebAppFilterChain.java:
223
)
at com.caucho.server.dispatch.ServletInvocation.service(ServletInvocation.java:
265
)
at com.caucho.server.http.HttpRequest.handleRequest(HttpRequest.java:
273
)
at com.caucho.server.port.TcpConnection.run(TcpConnection.java:
682
)
- locked <
0x00002aab3a6542f8
> (a java.lang.Object)
at com.caucho.util.ThreadPool$Item.runTasks(ThreadPool.java:
730
)
at com.caucho.util.ThreadPool$Item.run(ThreadPool.java:
649
)
at java.lang.Thread.run(Thread.java:
619
)
|
这其实是一个bug,在resin 3.1.9和3.1.11中日志翻转会遇到access log锁问题,导致同步锁不能正常释放线程被锁住。
bugid:
http://bugs.caucho.com/view.php?id=3509
http://bugs.caucho.com/view.php?id=4821
解决方法也比较简单:
1.升级resin到4.0.2以上的版本
2.如果不care resin的日志,可以diable掉记录日志的功能
本文转自菜菜光 51CTO博客,原文链接:http://blog.51cto.com/caiguangguang/1548047,如需转载请自行联系原作者