CPU占用很高排查方案

案例代码

/**
 * <pre>
 *    @author  : shkstart
 *    desc    : jstack 死锁案例
 *    version : v1.0
 * </pre>
 */
public class JstackDeadLockDemo {
    /**
     * 必须有两个可以被加锁的对象才能产生死锁，只有一个不会产生死锁问题
     */
    private final Object obj1 = new Object();
    private final Object obj2 = new Object();

    public static void main(String[] args) {
        new JstackDeadLockDemo().testDeadlock();
    }

    private void testDeadlock() {
        Thread t1 = new Thread(() -> calLock_Obj1_First());
        Thread t2 = new Thread(() -> calLock_Obj2_First());
        t1.start();
        t2.start();
    }

    /**
     * 先synchronized  obj1，再synchronized  obj2
     */
    private void calLock_Obj1_First() {
        synchronized (obj1) {
            sleep();
            System.out.println("已经拿到obj1的对象锁，接下来等待obj2的对象锁");
            synchronized (obj2) {
                sleep();
            }
        }
    }

    /**
     * 先synchronized  obj2，再synchronized  obj1
     */
    private void calLock_Obj2_First() {
        synchronized (obj2) {
            sleep();
            System.out.println("已经拿到obj2的对象锁，接下来等待obj1的对象锁");
            synchronized (obj1) {
                sleep();
            }
        }
    }

    /**
     * 为了便于让两个线程分别锁住其中一个对象，
     * 一个线程锁住obj1，然后一直等待obj2，
     * 另一个线程锁住obj2，然后一直等待obj1，
     * 然后就是一直等待，死锁产生
     */
    private void sleep() {
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}

运行代码

问题呈现

[root@wxl52d41 lele]# java JstackDeadLockDemo
已经拿到obj1的对象锁，接下来等待obj2的对象锁
已经拿到obj2的对象锁，接下来等待obj1的对象锁

问题分析

2.1查看进程

[root@wxl52d41 ~]# jps -l
23305 sun.tools.jps.Jps
28509 JstackDeadLockDemo

2.2 查询应用CPU、内存指标

top -Hp 28509

28532这个线程占比30%，比其他的都要高，怀疑此程序有问题

2.3 打印进行相关stack信息

[root@wxl52d41 ~]# jstack 28509 > jstack.log
[root@wxl52d41 ~]# vi jstack.log 
"Attach Listener" #11 daemon prio=9 os_prio=0 tid=0x00007f7540001000 nid=0x4468 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   
"DestroyJavaVM" #10 prio=5 os_prio=0 tid=0x00007f756804b800 nid=0x6f61 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   
"Thread-1" #9 prio=5 os_prio=0 tid=0x00007f7568208000 nid=0x6f76 waiting for monitor entry [0x00007f7556883000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at JstackDeadLockDemo.calLock_Obj2_First(JstackDeadLockDemo.java:49) 
        - waiting to lock <0x00000000e4861e30> (a java.lang.Object)
        - locked <0x00000000e4861e40> (a java.lang.Object)
        at JstackDeadLockDemo.lambda$testDeadlock$1(JstackDeadLockDemo.java:23)
        at JstackDeadLockDemo$$Lambda$2/1418481495.run(Unknown Source)
        at java.lang.Thread.run(Thread.java:750)
        
"Thread-0" #8 prio=5 os_prio=0 tid=0x00007f7568206000 nid=0x6f75 waiting for monitor entry [0x00007f7556984000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at JstackDeadLockDemo.calLock_Obj1_First(JstackDeadLockDemo.java:36) 
"jstack.log" 92L, 4540Chread dump OpenJDK 64-Bit Server VM (25.412-b08 mixed mode):

日志中线程pid是以16进制存储
把线程pid变为16进制如28532 - 》 6f74 然后得到0x6f74

或者通过一下命令查看

jstack 28509 | grep -A50  0x6f74

通过分析发现两个线程之间存在死锁

死锁线程：
Thread-1 和 Thread-0 之间存在死锁。
线程状态：
Thread-1：等待锁定对象 0x00000000e4861e30，但被 Thread-0 持有。
Thread-0：等待锁定对象 0x00000000e4861e40，但被 Thread-1 持有。
线程堆栈跟踪
Thread-1：
在 JstackDeadLockDemo.calLock_Obj2_First(JstackDeadLockDemo.java:49) 处等待锁定对象 0x00000000e4861e30。
已经锁定了对象 0x00000000e4861e40。
调用栈：
复制
at JstackDeadLockDemo.calLock_Obj2_First(JstackDeadLockDemo.java:49)

• waiting to lock <0x00000000e4861e30> (a java.lang.Object)
• locked <0x00000000e4861e40> (a java.lang.Object)
  at JstackDeadLockDemo.lambda$testDeadlock$1(JstackDeadLockDemo.java:23)atJstackDeadLockDemo$$Lambda$2/1418481495.run(Unknown Source)
  at java.lang.Thread.run(Thread.java:750)
  Thread-0：
  在 JstackDeadLockDemo.calLock_Obj1_First(JstackDeadLockDemo.java:36) 处等待锁定对象 0x00000000e4861e40。
  已经锁定了对象 0x00000000e4861e30。
  调用栈：
  复制
  at JstackDeadLockDemo.calLock_Obj1_First(JstackDeadLockDemo.java:36)
• waiting to lock <0x00000000e4861e40> (a java.lang.Object)
• locked <0x00000000e4861e30> (a java.lang.Object)
  at JstackDeadLockDemo.lambda$testDeadlock$0(JstackDeadLockDemo.java:22)atJstackDeadLockDemo$$Lambda$1/471910020.run(Unknown Source)
  at java.lang.Thread.run(Thread.java:750)

解决方案

（1）调整锁的顺序，保持一致
（2）或者采用定时锁，一段时间后，如果还不能获取到锁就释放自身持有的所有锁。

其他

查询应用进程id

jps 

查询应用CPU、内存指标

top -H -p PID

查询应用所有线程状态

jstack PID | grep 'java.lang.Thread.State' | awk '{print $2}'| sort| uniq -c
[root@wxl52d41 ~]# jstack 28509 | grep 'java.lang.Thread.State' | awk '{print $2}'| sort| uniq -c
      2 BLOCKED
      6 RUNNABLE
      2 WAITING

查询应用http请求线程数

jstack PID | grep 'http-nio' | wc -l

linux下统计各进程的tcp连接数

netstat -anp  | awk '{print $7}' |sort | uniq -c | sort -k1 -nr

dump应用线程栈信息

jstack PID > temp.log
less temp.log 

查询节点磁盘io读写情况

iostat -x 5