记一次tomcat无响应事件

机器环境

• Centos6 双核4G
• jdk1.7.0_71
• tomcat7.0.53

出现现象

在一次安全扫描的时候，进行到一半，nginx出现504错误。
进行服务器内， 用 curl测试tomcat服务，发现无响应。
使用htop查看内存及cpu占情况。
内存没占满，CPU占用80%左右。
检查数据库连接。数据库连接正常。

于是使用jstack导出tomcat的调用栈。

jstack调用栈信息分析

整个文件2188行。(正常情况下该项目jstack在500行左右)
文件比较长，不好直接看，所以先搜索统计。

0x1

以关键字http-bio-8080-exec-搜索。
有66个匹配，说明tcomat线程池中大概开了60多个活跃线程。

从最前面查看重复的调用栈。
卡在org.apache.tomcat.util.buf.UEncoder.initSafeChars函数上有39处。每处UEncoder.java的行数，有一样，有不一样,129,132等。

下载tomcat的源代码地址

第127行：safeChars=new BitSet(128);
感觉也没什么。
大概就是在UEncoder初始化的地方。
UEncoder是线程不安全的。

0x2

卡在java.lang.Long.parseLong上面有5处理。
这里是jdk的类，没有什么可以说的。

0x3

卡在http.URLParameter.clear(URLParameter.java:104)
http.URLParameter.clear(URLParameter.java:127)
有18处。
URLParameter.java是框架内的类。找到源码。
定位到104行：this.map.clear();
map的声明是private Map<String, Set<String>> map = new HashMap();这样的。

定位到127行

else for (String key : this.keys) {

keys的声明是这样的protected final String[] keys;

从感觉上猜测是回收map的时候出的问题。

0x4

找了下线程是阻塞状态的，只有两条State: BLOCKED

0x5

其中重复比较多的一个片段

"http-bio-8080-exec-99" daemon prio=10 tid=0x00007f08b445a000 nid=0xaee runnable [0x00007f08975e9000]
   java.lang.Thread.State: RUNNABLE
	at org.apache.tomcat.util.buf.UEncoder.initSafeChars(UEncoder.java:127)
	at org.apache.tomcat.util.buf.UEncoder.<init>(UEncoder.java:45)
	at org.apache.catalina.connector.Response.<init>(Response.java:258)
	at org.apache.catalina.connector.Connector.createResponse(Connector.java:895)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:374)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1040)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:313)
	- locked <0x00000000d21c8568> (a org.apache.tomcat.util.net.SocketWrapper)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

总的来说

从栈信息来说，虽然是有很多重复的地方，但没有找到可能的原因。
如果是map的清除，引起的gc，占用cpu的情况，也是有可能。
gc占用的CPU优先级比较高，然后GC未完成之前，分配内存很慢，并其它线程等待时间片。
但无法解释UEncoder的问题，UEncoder有的是卡在分配set上，有的是在for循环上。

最终是没有找到原因。缺少更准确和能深入诊断的手段。

这类问题属于综合性的问题，重现一次需要很长时间。
解决的思路：
1,尽量找能快速重现的方法
2,查看外部资源状态，检查外部系统依赖问题
3,查看内部线程状态

当时只用CPU和内存方面查看了系统状态，没有看下磁盘IO及网络IO方面的情况。
目前只用到了jstack，还应该综合其它诊断工具来排查问题。