Windows下JVM高CPU占用分析

Windows下JVM高CPU占用分析

线上Windows Server服务器出现卡顿情况,windows下不好用top命令,通过任务管理器查看,java.exe进程CPU占用长时间处于80%左右,严重消耗服务器资源。但进程是看不出具体是什么在占用CPU的,需要到线程维度分析。windows下查看线程不是很方便,需要下一个工具:ProcessExplorer

打开该软件,检查对应的java.exe进程,右键点击Properties,切换到Threads选项卡。

image-20210831092827713

可以看到该进程下所有的线程信息。TID即是线程号。

大致浏览发现,并非某个线程在占用CPU,而是很多线程分摊了系统CPU资源,所以不太可能是某个功能出现死循环之类的问题导致的。

随便找一个线程进一步分析,根据其所给的线程号,可以去查看对应的是什么功能在运行。这时需要我们导出当前的堆栈信息。

到对应java安装目录bin文件夹下,执行

1
jstack -l [java.exe的进程号] > stack.log

如果不清楚当前执行的java进程的进程号,也可以jps先看一下。

image-20210831093939393

大概长这样,右边的是进程名称,看具体情况而定。

导出来后,内容大致如图:

image-20220416161110239

相关参数释义:

  • “xxx”

    线程名称

  • prio

    线程优先级

  • tid

    即Thead ID,属于java级别的线程ID

  • nid

    即Native Thead ID,该ID高度依赖于系统平台,windows中就是对应的windows线程号;linux中,就是线程的PID;MacOS中,对应的原生pthread_t的值

堆栈信息导出来后,需要找到占用高的线程的堆栈,由于ProcessExplorer给的TID是十进制的,堆栈信息中的tid是十六进制的,需要转换一下,随便找个工具,比如windows自带的计算器:

image-20210831101057064

十进制(DEC)中,输入某个windows线程号,如19844,得到十六进制(HEX)下的0x4D84,在堆栈日志中查找这个值,

image-20210831101444530

好像不是啥关键的进程,而且该进程是BLOCKED状态,不是RUNNABLE应该不会太消耗CPU,我们可以换一个线程再观察一下:15628对应0x3d0c

是一个关于download的线程:

image-20210831102055708

后面观察了几个,也是关于download的。为了更方便分析,找了个在线堆栈分析的站点:https://gceasy.io/

image-20210831102334427

image-20210831102414574

主要观察RUNNABLE的线程,只有在运行才会占用CPU。下面的Threads with identical stack trace也为我们清楚的列出了具有相同堆栈的线程。

image-20210831102544740

确实,大量关于download的线程正在执行中。

找到其对应的url,并分析相关日志。

image-20210831102713483

两三个小时内有六千多个下载请求,而实际上,当前软件的用户量根本不会出现这么多请求。仔细观察日志:

image-20210831102859856

全是Baiduspider,也就是百度爬虫!原来如此,被爬了。。。

找到了原因就好解决了,应用根目录下添加个robots.txt,并定义哪些url不能被爬就可以了,或者应用内定义Filter,识别请求类型,如果是爬虫则进行拦截。

总结

  1. 多观察日志,可以更快速的定位问题。
  2. 还是尽量用工具去分析堆栈,纯文本看太慢了,不够直观。
  3. 还是尽量用linux把,windows下进程分析不太方便。