记录一次线上使用jvisualvm排查问题的过程

小名dang
2,155 阅读3分钟

背景：最近测试批量任务执行的时候发现服务器端的线程数时不时的会出现飙升，并且执行完之后不见下降。要知道出现多线程问题是比较头疼的，因为有时候一味的跟代码不一定能看出问题，还比较耗时。这时候就需要用到一些工具来监控线程的执行过程和状态，JDK自身提供了提供了很多工具来监控jvm运行状态，这些工具都放在bin目录下。这里主要使用的是jvisualvm工具来监控线程，并通过导出的线程dump文件分析问题所在。

一.linux上使用jvisualvm的方式

      jvisualvm打开是一个图形化界面


    如图所示，该软件可以监控本地的java进程的CPU，类，线程，的消耗情况，点击线程dump也可以比较方便的查看当前的dump日志。当然还有其他功能也支持插件暂时没涉到，以后慢慢摸索。

    可以看到有Local和Remote两种方式打开，这里介绍下用SecureCRT远程连接Linux 使用X11 转发功能打开图形化窗口：

    1.检查/etc/ssh/sshd_config文件，确保以下参数正确：

AllowTcpForwarding yes
##启用X11 
ForwardingX11Forwarding yes
X11UseLocalhost no

    2.重启sshd服务:

service sshd restart

    3.检查下linux服务器上是否安装了xorg-x11-xauth，如果没有则需要先安装xauth，命令如下：

yum install xorg-x11-xauth

   4.在windows主机安装Xming, 启动X server

下载地址：

sourceforge.net/projects/xm…
下载安装完直接启动就行。

    5.安装SecureCRT，并配置对应会话的转发X11

SecureCRT有绿色版直接解压打开即可，配置对应会话的转发X11如下图：


注意：配置完之后要重新打开会话连接。

    6.在SecureCRT建立的Linux会话界面cd到jdk安装路径的bin目录下直接启动

./jvisualvm

二.分析根据线程dump文件分析原因

通过分析下载下来的dump文件发现出现大量的类似以下的信息：

"pool-16-thread-55" #767 prio=5 os_prio=0 tid=0x00007f4a90035000 nid=0x13e6 waiting on condition [0x00007f4960eb8000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000005cfbdc670> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

   Locked ownable synchronizers:
	- None

大致介绍下上面的线程info信息快的内容

1. "pool-16-thread-55" #767 prio=5 os_prio=0 tid=0x00007f4a90035000 nid=0x13e6 waiting on condition [0x00007f4960eb8000]
# 线程名称：pool-16-thread-55；优先级: 5，默认是5；# JVM线程id：tid=0x00007f4a90035000，JVM内部线程的唯一标识（通过java.lang.Thread.getId()获取，通常用自增方式实现）。# 对应系统线程id（NativeThread ID）：nid=0x13e6 ，和top命令查看的线程pid对应，不过一个是10进制，一个是16进制。（通过命令：top -H -p pid，可以查看该进程的所有线程信息）# 线程状态：waiting on condition 
# 起始栈地址：[0x00007f4960eb8000]，对象的内存地址，通过JVM内存查看工具，能够看出线程是在哪儿个对象上等待；2.java.lang.Thread.State: WAITING (parking)
3.at sun.misc.Unsafe.park(Native Method)
4.- parking to wait for  <0x00000005cfbdc670> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
5.at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
6.at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)--等待任务进入
7.at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
8.at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)--获取执行任务
9.at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)--线程池运行
10.at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
11.at java.lang.Thread.run(Thread.java:748)

    由上面线程信息块可以发现的出结论大量的线程都处于waiting状态。并且引起waiting的原因是因为线程到任务队列获取任务时没获取到任务，导致线程被park住。也就是任务都执行完了但是线程还没被回收，原因可能是创建线程池时设置的核心线程数过大；也有可能创建了多个线程池实例，每次使用不同的线程池实例运行任务导致。接下来就是去对应的地方分析代码实现（ps:看别人的代码是真是一个痛苦的过程），通过分析代码发现每个服务都创建了对应的线程池去批量处理，而且每次添加新流程发布的时候都会重新创建一个新的流程线程池去执行服务。到这里问题的原因找到了，接下来就是修改代码了。

   分析线程dump文件时对于线程状态和为什么会产生该状态的原因要有一定的了解，不然即使有了线程信息也会一脸懵逼的。

具体的线程状态和产生原因可以参考下面的文章

juejin.cn/post/684490…


avatar
文章
阅读
粉丝