记录下查找Java应用占用CPU时间最长的线程的过程。
获取进程ID
使用jps指令获取java服务进程ID:
1 |
jps -l | grep serviceName |
命令结果如下:
1 2 |
$ jps -l | grep jspy 19064 org.chobit.jspy.JSpyApplication |
其中19064即是目标java服务进程ID。
查询线程占用时间
使用top -H -p pid指令查询指定进程下的线程占用CPU的信息。
其中“-H”说明查询线程信息,“-p”指示进程ID, pid为进程ID。
执行命令如下:
1 |
top -H -p top -H -p 42715 |
执行结果如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 |
Threads: 196 total, 0 running, 196 sleeping, 0 stopped, 0 zombie %Cpu(s): 8.0 us, 3.2 sy, 0.0 ni, 87.7 id, 0.6 wa, 0.0 hi, 0.5 si, 0.0 st KiB Mem : 65694712 total, 1032956 free, 43993144 used, 20668612 buff/cache KiB Swap: 15625212 total, 14352536 free, 1272676 used. 18000040 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 43225 hadoop 20 0 16.054g 2.953g 7760 S 1.3 4.7 36:32.27 java 44116 hadoop 20 0 16.054g 2.953g 7760 S 1.3 4.7 18:54.87 java 44064 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:53.78 java 44115 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:56.98 java 44120 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:55.52 java 44124 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:54.58 java 44126 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:54.16 java 44136 hadoop 20 0 16.054g 2.953g 7760 S 1.0 4.7 18:53.04 java 43997 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 16:30.26 java 43998 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 16:41.28 java 43999 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 16:16.98 java 44036 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 18:55.21 java 44037 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 18:53.45 java 44038 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 18:54.57 java 44039 hadoop 20 0 16.054g 2.953g 7760 S 0.7 4.7 18:53.30 java |
输入大写P(shift + p)可以查看占用CPU最多的线程;输入大写T(shift + t)可以查看占用CPU时间最长的线程。
结果中第一列为线程ID。这里的线程ID是十进制的。因为jstack中的线程ID是以十六进制表示,所以需要将线程ID转为十六进制。
以第一行的线程ID 43225为例,使用如下命令进行转换:
1 |
printf %x 43225 |
转换结果为:
1 2 |
$ printf %x 43225 a8d9 |
通过输出结果可知,43225对应的十六进制值是a8d9,通常记为“0xa8d9”。
找到线程进行定位
找到占用CPU较多的线程ID后,还需要将线程执行程序进行关联。
使用jstack命令打印线程堆栈信息,在堆栈信息中搜索十六进制的线程ID,如根据a8d9搜索到的结果为:
1 2 3 4 5 6 7 8 |
"AsyncAppender-Worker-async-PROCESSOR" #52 daemon prio=5 os_prio=0 tid=0x00007fa6f93c7000 nid=0xa8d9 waiting on condition [0x00007fa6b14f8000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0000000080b45790> (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.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403) at ch.qos.logback.core.AsyncAppenderBase$Worker.run(AsyncAppenderBase.java:264) |
注意堆栈信息中的“nid=0xa8d9”,nid即表示十六进制线程ID。
根据堆栈信息可以看出这个线程是日志打印线程,占用CPU时间较长也是可以理解的。
就这样。
其他
如果为目标应用启用了jvm监控服务(如JSPY)的话,这套流程会简单许多——只需要先排序再查看就可以了。
再记录下top指令的一些交互命令:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
c: 显示完整的命令 d: 更改刷新频率 f: 增加或减少要显示的列(选中的会变成大写并加*号) F: 选择排序的列 h: 显示帮助画面 H: 显示线程 i: 忽略闲置和僵死进程 k: 通过给予一个PID和一个signal来终止一个进程。(默认signal为15。在安全模式中此命令被屏蔽) l: 显示平均负载以及启动时间(即显示影藏第一行) m: 显示内存信息 M: 根据内存资源使用大小进行排序 N: 按PID由高到低排列 o: 改变列显示的顺序 O: 选择排序的列,与F完全相同 P: 根据CPU资源使用大小进行排序 q: 退出top命令 r: 修改进程的nice值(优先级)。优先级默认为10,正值使优先级降低,反之则提高的优先级 s: 设置刷新频率(默认单位为秒,如有小数则换算成ms)。默认值是5s,输入0值则系统将不断刷新 S: 累计模式(把已完成或退出的子进程占用的CPU时间累计到父进程的MITE+ ) T: 根据进程使用CPU的累积时间排序 t: 显示进程和CPU状态信息(即显示影藏CPU行) u: 指定用户进程 W: 将当前设置写入~/.toprc文件,下次启动自动调用toprc文件的设置 <: 向前翻页 >: 向后翻页 ?: 显示帮助画面 1(数字1): 显示每个CPU的详细情况 |
发表评论