top + jstack 定位java线程问题

发表于 | 分类于

jps -l

定位CPU高问题

1
2
3
4
5
6
7
8
9
# 1. 使用 top 定位到占用CPU高的进程PID
top
# 2. 获取线程信息，并找到占用CPU高的线程
top -Hp pid
ps -mp pid -o THREAD,tid,time | sort -rn
# 3. 将需要的线程ID转换为16进制格式
printf "%x\n" tid
# 4. 打印线程的堆栈信息
jstack pid | grep tid -A 30

top -Hp pid

top -Hp pid 可以查看某个进程的线程信息

-H 显示线程信息，-p指定pid

可以看到 线程 26096 已经运行了17个小时，将 26096 转化为 16进制：65f0；

[root@localhost ~]# printf “%x\n” 27565

线程 27565 对应的 16进制编码为：6bad

各字段含义

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
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
统计信息区前五行是系统整体的统计信息。第一行是任务队列信息，同 uptime 命令的执行结果。其内容如下：
01:06:48    当前时间
up 1:22    系统运行时间，格式为时:分
1 user    当前登录用户数
load average: 0.06, 0.60, 0.48    系统负载，即任务队列的平均长度。三个数值分别为 1分钟、5分钟、15分钟前到现在的平均值。


第二、三行为进程和CPU的信息。当有多个CPU时，这些内容可能会超过两行。内容如下：
total 进程总数
running 正在运行的进程数
sleeping 睡眠的进程数
stopped 停止的进程数
zombie 僵尸进程数
Cpu(s): 
0.3% us 用户空间占用CPU百分比
1.0% sy 内核空间占用CPU百分比
0.0% ni 用户进程空间内改变过优先级的进程占用CPU百分比
98.7% id 空闲CPU百分比
0.0% wa 等待输入输出的CPU时间百分比
0.0%hi：硬件CPU中断占用百分比
0.0%si：软中断占用百分比
0.0%st：虚拟机占用百分比
 

最后两行为内存信息。内容如下：
Mem:
191272k total    物理内存总量
173656k used    使用的物理内存总量
17616k free    空闲内存总量
22052k buffers    用作内核缓存的内存量
Swap: 
192772k total    交换区总量
0k used    使用的交换区总量
192772k free    空闲交换区总量
123988k cached    缓冲的交换区总量,内存中的内容被换出到交换区，而后又被换入到内存，但使用过的交换区尚未被覆盖，该数值即为这些内容已存在于内存中的交换区的大小,相应的内存再次被换出时可不必再对交换区写入。
 
怎么看内存有多少空闲呢？
totalfree = free17616 + buffers22052 + cached123988


进程信息区统计信息区域的下方显示了各个进程的详细信息。首先来认识一下各列的含义。
序号  列名    含义
a    PID     进程id
b    PPID    父进程id
c    RUSER   Real user name
d    UID     进程所有者的用户id
e    USER    进程所有者的用户名
f    GROUP   进程所有者的组名
g    TTY     启动进程的终端名。不是从终端启动的进程则显示为 ?
h    PR      优先级
i    NI      nice值。负值表示高优先级，正值表示低优先级
j    P       最后使用的CPU，仅在多CPU环境下有意义
k    %CPU    上次更新到现在的CPU时间占用百分比
l    TIME    进程使用的CPU时间总计，单位秒
m    TIME+   进程使用的CPU时间总计，单位1/100秒
n    %MEM    进程使用的物理内存百分比
o    VIRT    进程使用的虚拟内存总量，单位kb。VIRT=SWAP+RES
p    SWAP    进程使用的虚拟内存中，被换出的大小，单位kb。
q    RES     进程使用的、未被换出的物理内存大小，单位kb。RES=CODE+DATA
r    CODE    可执行代码占用的物理内存大小，单位kb
s    DATA    可执行代码以外的部分(数据段+栈)占用的物理内存大小，单位kb
t    SHR     共享内存大小，单位kb
u    nFLT    页面错误次数
v    nDRT    最后一次写入到现在，被修改过的页面数。
w    S       进程状态(D=不可中断的睡眠状态,R=运行,S=睡眠,T=跟踪/停止,Z=僵尸进程)
x    COMMAND 命令名/命令行
y    WCHAN   若该进程在睡眠，则显示睡眠中的系统函数名
z    Flags   任务标志，参考 sched.h
 
cpu使用率很高，所以首先找到该进程，通过top命令，监控该进程的使用率，然后通过H，查看各个线程的cpu使用率情况，记下cpu使用率高的线程id，然后通过jstack pid,获取各个线程栈，听过top获取的线程id转化成16进制后

jstack pid

jstack 用法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
/opt/java8/bin/jstack

Usage:
    jstack [-l] <pid>
        (to connect to running process) 连接活动线程
    jstack -F [-m] [-l] <pid>
        (to connect to a hung process) 连接阻塞线程
    jstack [-m] [-l] <executable> <core>
        (to connect to a core file) 连接dump的文件
    jstack [-m] [-l] [server_id@]<remote server IP or hostname>
        (to connect to a remote debug server) 连接远程服务器

Options:
    -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)
    -m  to print both java and native frames (mixed mode)
    -l  long listing. Prints additional information about locks
    -h or -help to print this help message

使用 jstack 打印 进程 26080 的线程堆栈

jstack 26080 > aaa.log


正向推导

jstack 26080 | grep 6bad -A 30

线程 26080（16进制：6bad） 的线程堆栈如下：

各字段含义

  • pool-1-thread-3：线程名；
  • prio：应该是线程的优先级；
  • os_prio：对应的操作系统的 线程优先级；
  • tid：jvm 中 的线程id；
  • nid： tid映射的操作系统中的线程id,非常有用,不过这里是用16进制的表示。可以通过 printf “%x\n” 十进制数字 查找一个十进制数字的十六进制表示；
  • waiting for condition：等待资源ID；
  • TIMED_WAITING：当前线程状态；

反向推导

同理，nid=0x6f44 对应的线程ID 为 28484：

top -Hp 26080 | grep 28484


jstack解析示例

0、线程状态

jstack dump 日志文件中，值得关注的线程状态有：

  1. 死锁，Deadlock（重点关注）
  2. 执行中，Runnable
  3. 等待资源，Waiting on condition（重点关注）
  4. 等待获取监视器，Waiting on monitor entry（重点关注）
  5. 暂停，Suspended
  6. 对象等待中，Object.wait() 或 TIMED_WAITING
  7. 阻塞，Blocked（重点关注）
  8. 停止，Parked

  • pool-1-thread-3：线程名；
  • prio：应该是线程的优先级；
  • os_prio：对应的操作系统的 线程优先级；
  • tid：jvm 中 的线程id；
  • nid： tid映射的操作系统中的线程id,非常有用,不过这里是用16进制的表示。可以通过 printf “%x\n” 十进制数字 查找一个十进制数字的十六进制表示；
  • waiting for condition：等待资源ID；
  • TIMED_WAITING：当前线程状态；

1、Object.wait() + locked

1
2
3
4
5
6
"Timer-0" #22 daemon prio=5 os_prio=0 tid=0x00007fc29cb23800 nid=0x65ff in Object.wait() [0x00007fc28474c000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.util.TimerThread.mainLoop(Timer.java:552)
        - locked <0x00000006c064fa10> (a java.util.TaskQueue)
        at java.util.TimerThread.run(Timer.java:505)
  1. locked：线程拿到了 synchornized 锁 Object；
  2. Object.wait()：线程调用了 wait(n)，释放了锁，进入到Wait Set队列；
  3. TIMED_WAITING：线程处于 TIMED_WAITING 状态；

2、waiting on condition

1
2
3
4
5
6
7
8
9
10
11
"pool-1-thread-1" #19 prio=5 os_prio=0 tid=0x00007fc220003800 nid=0x65fa waiting on condition [0x00007fc2851bb000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000006c0414240> (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:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
  1. ConditionObject.await：线程调用了 Condition 的 await 方法，释放了锁，同时进入WAITING 状态；
  2. 线程在 等待 其他线程 使用 Condition.signal() 将它唤醒

3、runnable

1
2
3
4
5
6
7
8
9
"1414013111@qtp-802771878-1 - Acceptor0 SocketConnector@0.0.0.0:8081" #21 prio=5 os_prio=0 tid=0x00007fc29cb14800 nid=0x65fe runnable [0x00007fc28484d000]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
        at java.net.ServerSocket.implAccept(ServerSocket.java:545)
        at java.net.ServerSocket.accept(ServerSocket.java:513)
        at org.mortbay.jetty.bio.SocketConnector.accept(SocketConnector.java:99)
        at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708)
        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)

RUNNABLE：线程处于可运行状态 或 正在运行；