Java线程诊断

2023-02-15,,

1.诊断CPU占用过高

[root@master ~]# nohup java -jar JvmProject.jar & // 有问题的java程序
[1] 1627
[root@master ~]# nohup: ignoring input and appending output to ‘nohup.out’

1.1使用top命令来查看是那个程序占用CPU过高

top - 08:57:03 up 25 min,  1 user,  load average: 0.49, 0.77, 0.58
Tasks: 104 total, 1 running, 103 sleeping, 0 stopped, 0 zombie
%Cpu(s): 99.7 us, 0.3 sy, 0.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 995464 total, 359540 free, 290336 used, 345588 buff/cache
KiB Swap: 1048572 total, 1048572 free, 0 used. 557932 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1710 root 20 0 2241412 28948 11752 S 99.9 2.9 0:09.24 java
1655 root 20 0 0 0 0 S 0.3 0.0 0:00.28 kworker/0:1
1 root 20 0 125484 3892 2584 S 0.0 0.4 0:01.38 systemd
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
4 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H
5 root 20 0 0 0 0 S 0.0 0.0 0:00.07 kworker/u256:0
6 root 20 0 0 0 0 S 0.0 0.0 0:00.06 ksoftirqd/0

1.2使用ps -H -eo pid,tid,%cpu | grep 进程ID(用PS命令进一步定位是哪个线程引起的cpu占用过高)

[root@master ~]# ps -H -eo pid,tid,%cpu | grep 1790
1790 1790 99.5

1.3.jstack 进程ID 查看该进程中的所有java线程信息

​ 通过进程的id与jstack的结果进行匹配,由于linux中进程id是10进制而java中是16进制所以需要使用进制转换,进程1790+10转换成16进制为708 (在虚拟机中不知道什么原因pid+10 = tid)

[root@master ~]# jstack 1790
2023-01-10 09:05:45
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.202-b08 mixed mode): "Attach Listener" #12 daemon prio=9 os_prio=0 tid=0x00007f1d64001000 nid=0x72a waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "DestroyJavaVM" #11 prio=5 os_prio=0 tid=0x00007f1d8c009000 nid=0x6ff waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "thread3" #10 prio=5 os_prio=0 tid=0x00007f1d8c140000 nid=0x70a waiting on condition [0x00007f1d6968c000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.aircoinst.Demo1_6.lambda$main$2(Demo1_6.java:24)
at com.aircoinst.Demo1_6$$Lambda$3/250421012.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748) "thread2" #9 prio=5 os_prio=0 tid=0x00007f1d8c13e000 nid=0x709 waiting on condition [0x00007f1d6978d000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at com.aircoinst.Demo1_6.lambda$main$1(Demo1_6.java:15)
at com.aircoinst.Demo1_6$$Lambda$2/455659002.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748) "thread1" #8 prio=5 os_prio=0 tid=0x00007f1d8c13c000 nid=0x708 runnable [0x00007f1d6988e000]
java.lang.Thread.State: RUNNABLE
at com.aircoinst.Demo1_6.lambda$main$0(Demo1_6.java:7) # 该处就是CPU占用过高问题所在(问题代码在第七行)
at com.aircoinst.Demo1_6$$Lambda$1/1406718218.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748) "Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f1d8c0db800 nid=0x706 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f1d8c0d8800 nid=0x705 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f1d8c0d6800 nid=0x704 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f1d8c0d4800 nid=0x703 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f1d8c0a1800 nid=0x702 in Object.wait() [0x00007f1d7c422000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000f0c08ed0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x00000000f0c08ed0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216) "Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f1d8c09e800 nid=0x701 in Object.wait() [0x00007f1d7c523000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000f0c06bf8> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x00000000f0c06bf8> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153) "VM Thread" os_prio=0 tid=0x00007f1d8c095000 nid=0x700 runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007f1d8c0de800 nid=0x707 waiting on condition JNI global references: 311

​ 红色框内就是问题代码,所以该问题可以根据线程id找到有问题的线程,进一步定位到问题代码的源码行号,进行问题分析。

2.程序运行很长时间没有结果

[root@master ~]# nohup java -jar JvmProject.jar &
[1] 1901
[root@master ~]# nohup: ignoring input and appending output to ‘nohup.out’
# 该地方没有程序输出,一直为卡死状态
[root@master ~]#

2.1 使用jps命令查询进程信息,进程id为1901

[root@master ~]# jps
1913 Jps
1901 jar

2.2 使用jstack 进程id命令查看所有线程信息

[root@master ~]# jstack 1901
2023-01-10 09:25:28
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.202-b08 mixed mode): "Attach Listener" #11 daemon prio=9 os_prio=0 tid=0x00007fde70001000 nid=0x78d waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE "DestroyJavaVM" #10 prio=5 os_prio=0 tid=0x00007fde9c009000 nid=0x76e waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
....
....
Found one Java-level deadlock: # 产生了死锁
=============================
"Thread-1":
waiting to lock monitor 0x00007fde7c004e28 (object 0x00000000f0c674c0, a com.aircoinst.A),
which is held by "Thread-0"
"Thread-0":
waiting to lock monitor 0x00007fde7c0062c8 (object 0x00000000f0c68a80, a com.aircoinst.B),
which is held by "Thread-1" Java stack information for the threads listed above:
===================================================
"Thread-1":
at com.aircoinst.Demo1_7.lambda$main$1(Demo1_7.java:35) # 死锁问题代码行
- waiting to lock <0x00000000f0c674c0> (a com.aircoinst.A) # 等待A对象的锁
- locked <0x00000000f0c68a80> (a com.aircoinst.B) # 当前锁住了B对象
at com.aircoinst.Demo1_7$$Lambda$2/295530567.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748)
"Thread-0":
at com.aircoinst.Demo1_7.lambda$main$0(Demo1_7.java:27) # 死锁问题代码行
- waiting to lock <0x00000000f0c68a80> (a com.aircoinst.B) # 等待B对象的锁
- locked <0x00000000f0c674c0> (a com.aircoinst.A) # 当前锁住了A对象
at com.aircoinst.Demo1_7$$Lambda$1/250421012.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748) Found 1 deadlock.

对比源代码,发现线程1与线程2同时发生了死锁,造成了相A,B对象互等待释放

Java线程诊断的相关教程结束。

《Java线程诊断.doc》

下载本文的Word格式文档,以方便收藏与打印。