通过jstack定位在线运行java系统故障_案例1

问题描述：

在一个在线运行的java web系统中，会定时运行一个FTP上传的任务，结果有一天发现，文件正常生成后却没有上传。

问题初步分析：

1.查看日志文件

发现这个任务只打印了开始进入FTP处理的日志，但是没有打印FTP处理完成的日志。

从代码上看，FTP上传处理的代码异常保护都非常的好，如果出现异常，就会进行打印，而日志文件中却没有相关的信息，甚是奇怪。怀疑是FTP过程问题，如对方FTP服务器有什么问题导致，但是却找不到证据。

苦于无法窥探java运行系统内部信息，祭出杀手锏-jstack。

2.通过jstack分析

在运行系统上，通过jps命令（也可以通过其他方式，如ps）查看运行中的java程序的进程ID，使用jstack pid > jstack.log 将线程堆栈信息导出到jstack.log文件中，找到如下有用的信息。

通过代码确认，下方的UploadFtpTask确实就是我们的文件上传任务的执行代码。

通过堆栈信息看，线程状态为RUNNABLE,不是BLOCKED状态，说明不是因为锁导致线程阻塞，而是阻塞在了网络读取上。

<span style="font-size:14px;">"DefaultQuartzScheduler_Worker-5" prio=10 tid=0x00002aaaf4382801 nid=0x1874 runnable [0x000000004133b000..0x000000004133bda0]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)
        at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:306)
        at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:158)
        - locked <0x00002aaac3cdd061> (a java.io.InputStreamReader)
        at sun.nio.cs.StreamDecoder.read0(StreamDecoder.java:107)
        - locked <0x00002aaac3cdd061> (a java.io.InputStreamReader)
        at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:93)
        at java.io.InputStreamReader.read(InputStreamReader.java:151)
        at it.sauronsoftware.ftp4j.NVTASCIIReader.readLine(NVTASCIIReader.java:105)
        at it.sauronsoftware.ftp4j.FTPCommunicationChannel.read(FTPCommunicationChannel.java:142)
        at it.sauronsoftware.ftp4j.FTPCommunicationChannel.readFTPReply(FTPCommunicationChannel.java:187)
        at it.sauronsoftware.ftp4j.FTPClient.connect(FTPClient.java:1034)
        - locked <0x00002aaac3cdd109> (a java.lang.Object)
        at com.xx.FtpClientImpl.connect(FtpClientImpl.java:56)
        at com.xx.UploadFtpTask.execute(UploadFtpTask.java:88)
        at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)</span>

通过引用的jar包确认，这个FTP功能使用的开源包ftp4j来实现的，使用的版本为1.5.1。

写个测试程序，看看FTP连接时的调用堆栈：

Socket.connect(SocketAddress) line: 469 
Socket.<init>(SocketAddress, SocketAddress, boolean) line: 366 
Socket.<init>(String, int) line: 180 
DirectConnector.connect(String, int) line: 35 
DirectConnector.connectForCommunicationChannel(String, int) line: 40 
FTPClient.connect(String, int) line: 1024 
FTPClient.connect(String) line: 991 
Test.main(String[]) line: 19 

而Socket 的469行是什么呢？

connect(endpoint, 0); 

这个函数的定义为：public void connect(SocketAddress endpoint, int timeout)  ，上面的调用相当于设置了timeout为0，那就意味着出现网络丢包或者对端服务有问题时，这个连接会无限制等待下去。这就杯具了。

再看看这个开源项目后续是否对此问题做过修改呢？下载1.7.2版本,再次测试，查看调用堆栈：

Socket.connect(SocketAddress, int) line: 490 
DirectConnector(FTPConnector).tcpConnectForCommunicationChannel(String, int) line: 208 
DirectConnector.connectForCommunicationChannel(String, int) line: 39 
FTPClient.connect(String, int) line: 1036 
FTPClient.connect(String) line: 1003 
Test.main(String[]) line: 19

通过tcpConnectForCommunicationChannel去调用Socket的connect方法时，传入了超时时间，为10秒（10*1000）。这就引入了超时机制，如果出现上面问题时，就不会死等了。

总结：

1.jstack工具是定位在线运行java系统的利器，可以查看线程堆栈信息，这对于分析问题非常重要，特别是在日志分析和代码分析无法确定问题时。

2.网络连接时，必须设置超时，不能无限制等待。发散一下，开发系统时，必须考虑各种异常情况。套用那句话，出来混，总是要还的。

转载请注明出处：http://blog.csdn.net/u014569459/article/details/38542949