您的位置:首页 > Web前端 > JavaScript

JVM调优之jstack找出最耗cpu的线程并定位代码

2017-09-06 19:32 295 查看
jstack可以定位到线程堆栈,根据堆栈信息我们可以定位到具体代码,所以它在JVM性能调优中使用得非常多。下面我们来一个实例找出某个Java进程中最耗费CPU的Java线程并定位堆栈信息,用到的命令有ps、top、printf、jstack、grep。第一步先找出Java进程ID,服务器上的Java应用名称为mrf-center:
root@ubuntu:/# ps -ef | grep mrf-center | grep -v grep
root     21711     1  1 14:47 pts/3    00:02:10 java -jar mrf-center.jar
得到进程ID为21711,第二步找出该进程内最耗费CPU的线程,可以使用
1)ps -Lfp pid--替换你的进程id
2)ps -mp pid -o THREAD, tid, time
3)top -Hp pid--替换你的进程id
top -Hp pid 输出信息的含义:
-Hp “H”的解释:如果输入大写P,则结果按CPU占用降序排序。如果输入大写M,结果按内存占用降序排序。H是打开或者关闭显示线程信息的开关。
但是显示如下:
[root@sncdpreweb04 ~]# top -p 6766
top - 15:54:36 up 261 days, 23:18,  1 user,  load average: 11.95, 13.60, 14.16
Tasks:  26 total,   2 running,  24 sleeping,   0 stopped,   0 zombie
Cpu(s): 96.8%us,  3.1%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.1%st
Mem:   8059780k total,  5821348k used,  2238432k free,    65636k buffers
Swap: 10485752k total,  2696164k used,  7789588k free,   269240k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                            
11136 root      20   0 5514m 1.3g  10m R 37.0 16.5   0:12.81 java                                                                                                                                                                
 6784 root      20   0 5514m 1.3g  10m R 27.6 16.5   4:09.61 java                                                                                                                                                                
 6785 root      20   0 5514m 1.3g  10m S 27.0 16.5   4:01.17 java                                                                                                                                                                
 6772 root      20   0 5514m 1.3g  10m S  3.0 16.5   0:15.53 java                                                                                                                                                                
 6770 root      20   0 5514m 1.3g  10m S  2.0 16.5   0:15.42 java                                                                                                                                                                
 6778 root      20   0 5514m 1.3g  10m S  2.0 16.5   0:15.58 java                                                                                                                                                                
 6777 root      20   0 5514m 1.3g  10m S  1.7 16.5   0:15.66 java                                                                                                                                                                
 6780 root      20   0 5514m 1.3g  10m S  0.7 16.5   0:09.25 java                                                                                                                                                                
 6828 root      20   0 5514m 1.3g  10m S  0.7 16.5   0:13.31 java                                                                                                                                                                
 6786 root      20   0 5514m 1.3g  10m S  0.3 16.5   0:41.63 java                                                                                                                                                                
 6766 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java                                                                                                                                                                
 6769 root      20   0 5514m 1.3g  10m S  0.0 16.5   8:59.85 java                                                                                                                                                                
 6781 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.22 java                                                                                                                                                                
 6782 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.26 java                                                                                                                                                                
 6783 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java                                                                                                                                                                
 6787 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java                                                                                                                                                                
 6788 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:01.93 java                                                                                                                                                                
 6820 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java                                                                                                                                                                
 6823 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java                                                                                                                                                                
 6824 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.02 java                                                                                                                                                                
 6825 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.03 java                                                                                                                                                                
 6826 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:01.28 java                                                                                                                                                                
 6827 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.10 java                                                                                                                                                                
 6829 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.05 java                                                                                                                                                                
 6830 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.35 java                                                                                                                                                                
 8915 root      20   0 5514m 1.3g  10m S  0.0 16.5   0:00.00 java   
为什么 pid展示的是进程id,而且还有6766这个线程????
The four threads will have the same PID but only when viewed from above. What you (as a user) call a PID is not what the kernel (looking from below) calls a PID.In the kernel, each thread has it's own ID, called a PID (although it would possibly make more sense to call this a TID, or thread ID) and they also have a TGID (thread group ID) which is the PID of the thread that started the whole process.Simplistically, when a new process is created, it appears as a thread where both the PID and TGID are the same (new) number.When a thread starts another thread, that started thread gets its own PID (so the scheduler can schedule it independently) but it inherits the TGID from the original thread.That way, the kernel can happily schedule threads independent of what process they belong to, while processes (thread group IDs) are reported to you.翻译:
四个线程将具有相同的PID,但仅在从上方观察时。 您(作为用户)调用PID不是内核(从下面看)调用PID。
在内核中,每个线程都有自己的ID,称为PID(尽管将其称为TID或线程ID可能更有意义),并且它们还具有作为线程的PID的TGID(线程组ID) 开始了整个过程。
简单来说,当一个新进程被创建时,它显示为一个线程,PID和TGID都是相同的(新的)数字。
当一个线程启动另一个线程时,该线程获得自己的PID(因此调度程序可以独立调度),但它会从原始线程继承TGID。
这样,内核可以高兴地安排线程,而不管它们属于什么进程,而进程(线程组ID)则会报告给您。 
*******************************************************************************************************************************************
输出信息解释
*******************************************************************************************************************************************
(1)一前面两行信息
16:03:58 表示系统当前时间。up 23:55,表示系统已经运行时间。17 users,当前登录的用户数。load average: 3.39 , 3.88 , 3.62。这分别表示内核任务队列在1分钟、5分钟、15分钟的长度。就是通常我们说的负载。Tasks:288 total。当前系统的进程总数。4 running,当前系统中有4个正在运行的进程。284 sleeping ,当前系统中有284个休眠的进程。0 stopped 。停止进程数为0。0 zombie。僵死进程数为0。(二)CPU信息%us。用户空间进程占用CPU时间的百分比。%sy。内核空间进程占用CPU时间的百分比。%ni。ni表示nice的意思,也就是哪些用户进程被提升优先级之后,占用的CPU运行时间。%id。系统空闲时间。%wa。这个表示CPU在等待磁盘写入的时间。%si。CPU处理软中断(soft interrupt)的时间百分比。%hi。CPU处理硬中断(hard interrupt)的时间百分比。%st。这个表示在有虚拟机的时候,被虚拟机占用的CPU时间。st表示窃取的意思,steal的意思。很明显,上面这些百分比相加的话,是等于100%的。这只表示单个CPU的运行状况。(三)内存使用信息total。表示系统可用的物理内存总量。used。当前已经使用的物理内存总量。free。当前的空闲内存总量。buffers。用作系统内核缓存的物理内存总量。(四)系统交换区信息total。系统全部的交换区总量。used。当前已经使用的交换区总量。free。空闲的交换区总量。cached。被缓冲的交换区总量。(五)进程信息PID。进程ID。USER。当前进程的用户,就是这个进程是由谁来执行的。PR。进程执行优先级。NI。当前进程的NICE值。nice值可以调整进程运行的优先级。VIRT。当前进程对虚拟内存使用量。RES。当前进程的物理内存使用量。SHR。当前进程的共享内存使用量。S。当前进程的状态,可以是R= 正在运行状态,S=休眠状态,D=不可中断的睡眠状态,T=跟踪/停止,Z=僵尸进程%CPU。当前进程使用CPU的百分比。%MEM。当前进程使用内存的百分比。TIME+。当前进程的累计CPU占用时间COMMAND。当前进程的命令行*************************************************************************************************************************************
用第三个,输出如下:
TIME列就是各个Java线程耗费的CPU时间,CPU时间最长的是线程ID为21742的线程,用
printf "%x\n" 21742
得到21742的十六进制值为54ee,下面会用到。OK,下一步终于轮到jstack上场了,它用来输出进程21711的堆栈信息,然后根据线程ID的十六进制值grep,如下:
root@ubuntu:/# jstack 21711 | grep 54ee"PollIntervalRetrySchedulerThread" prio=10 tid=0x00007f950043e000 nid=0x54ee in Object.wait()
可以看到CPU消耗在PollIntervalRetrySchedulerThread这个类的Object.wait(),我找了下我的代码,定位到下面的代码:
// Idle waitgetLog().info("Thread [" + getName() + "] is idle waiting...");schedulerThreadState = PollTaskSchedulerThreadState.IdleWaiting;long now = System.currentTimeMillis();long waitTime = now + getIdleWaitTime();long timeUntilContinue = waitTime - now;synchronized(sigLock) {try {if(!halted.get()) {sigLock.wait(timeUntilContinue);}}catch (InterruptedException ignore) {}}
它是轮询任务的空闲等待代码,上面的sigLock.wait(timeUntilContinue)就对应了前面的Object.wait()。
内容来自用户分享和网络整理,不保证内容的准确性,如有侵权内容,可联系管理员处理 点击这里给我发消息
标签: