在应用运行过程中,除了遇到 Bug,执行结果不符合我们的预期之外,还有些时候是应用的响应问题。
比如同样对于页面的请求,正常情况下两秒之内就返回了结果,页面已经渲染完成展现出来了。
那不正常的时候,就会看到页面请求在不断的加载中,没有拿到响应。当然这个时候可以分析的点有很多:
- 可能操作系统的CPU、内存等资源占用比较多;
- 也有可能是应用内线程较多在等待;
- 还有可能是涉及到读数据库等操作时遇到锁之类的问题。
这次先不理会操作系统层面上的东西,只来分析应用内可能遇到的情况。
回到前面说的问题,正常情况两秒钟返回了,这次一分钟还没返回。这个时候,关注应用内的话,就需要分析一下其线程执行情况,来了解了定位具体问题。
此时,这次要提到的这个「武器」jstack 可以快速定位,直达患处。
是什么
jstac 是什么? 这个是 Oracle JDK 默认包含的一个用于打印执行 Java 进程的当前线程栈信息的工具。官方是这样介绍的:
jstack prints Java stack traces of Java threads for a given Java process or core file or a remote debug server. For each Java frame, the full class name, method name, 'bci' (byte code index) and line number, if available, are printed. |
注意其中几个关键点:每一个 Java Frame 的全类名,方法名,如果能拿到行号的话还会显示行号。看过前面介绍调试技巧那篇文章(80%的程序员都不了解的调试技巧)的朋友可能还记得,其中有一个功能是Drop Frame, 来实现后退执行。和这里的是一个地方,都对应线程中的一级调用。
使用 jstack 打出来的信息,和一般应用遇到异常时的printStackTrace 基本一样,只是那只是一个线程调用链的,这里通过工具,可以把应用内所有线程都打出来。
用法
使用方式和一般的 Java 分析工具类似,都是通过
命令名 <可选参数> + pid(进程id) |
这种格式使用。比如对于 jstack, 一般可以直接 jstack 应用pid 即可。这里 pid 可以通过Java的 jps 工具获取,也可以通过 Linux 下的ps 工具和 Windows 下的任务管理器获取。
输出
我们以一个Tomcat进程为例,输出类似这样:
我们看上面的几个框:
最上方左侧,是当前线程的线程名称,可以根据此来在应用内大量的线程中找到我们关心的线程正在执行的操作。例如 Tomcat 一般 http-port -x 这种线程是请求的处理线程,页面响应慢的时候,可以直接找这一类线程。
随着请求的增多,线程数也会很多。所以一般多线程应用开发,一个好的实战建议是为创建的线程起一个有意义的名字,否则打出来的 stack 里大量的 thread -1, thread -2 这种,天晓得哪一个才是你的。
第二行的框内内容,表示当前线程的执行状态,是运行状态还是TIME_WAITING,还是等待锁等,可以根据线程状态来了解。
第三个大框中的内容就和我们异常时输出的 stackTrace 一样,是当前代码的调用链。
第四个框中的内容,是当前线程挂的锁的情况。
上面的截图,是没有锁互相占用的情况下的输出。如果一个多线程中有锁等待时,会有类似这样的输出:
注意,此时线程状态变成了 BLOCKED, 同时,在线程的调用链中,有一个waiting to lock 的输出, 同时,在下方持胡锁的线程中,会有一个 lock xxx,这个是当前锁对象,通过这个就可以看出当前还有哪些线程在等待同一个锁。
所以回到前面的问题,如果此时因为锁占用导致的,可以从输出中看到,同时如果是数据库连接池满了,线程就会停在数据库连接的操作上,在 stackTrace 中一眼就能看的出来,甚至网络 Socket 读取之类的在等待,都会在调用链中体现出来,从而可以快速的定位问题,解决问题。
那对于应用的观察分析,还需要注意的是,可以间隔几秒钟时间执行一下 jstack,分析一下输出,然后对比一下几次输出的区别,看看这一段时间内应用有哪些地方在执行,分析和解决问题。
【本文为51CTO专栏作者“侯树成”的原创稿件,转载请通过作者微信公众号『Tomcat那些事儿』获取授权】