Java线程诊断

发布时间 2023-03-22 19:09:19作者: MineLSG

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对象互等待释放