CPU升高的排查步骤和分析思路
核心排查步骤
top命令：查看所有进程占系统CPU的排序
-
top -p pid ：查看进程的cpu
image.png -
top -Hp pid 定位使用 CPU 最高的线程
image.png printf '%x\n"' tid ：线程 id 转化 16 进制 (对应线程堆栈nid是十六进制)
> printf '%x\n' 12817
> 3211
5.jstack pid | grep nid ：找到线程堆栈
jstack 12816 | grep 3211 -A 30
分析
通过核心排查步骤，找出有问题的代码，观察到线程栈之后。我们就要根据具体问题来具体分析。
情况一：发现使用CPU最高的是业务线程
代码中有大量消耗CPU的操作，导致CPU过高，系统运行缓慢。可直接定位到代码行。例如某些复杂算法，甚至算法BUG，无限循环递归等等情况二：发现使用CPU最高的都是GC 线程
GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fd99001f800 nid=0x779 runnable
GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fd990021800 nid=0x77a runnable
GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007fd990023000 nid=0x77b runnable
GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007fd990025000 nid=0x77c runnabl
排查代码是否有内存泄漏等问题，见JAVA线上问题排查-内存篇
- 情况三：一和二都正常，排查是否是上下文切换引起的。见下文。
上下文切换引起的CPU升高
上下文切换相关的基础知识，请见linux基础知识-CPU-上下文切换
可以用 vmstat 和 pidstat 两个工具监控
vmstat查看系统总体的上下文切换情况
vmstat是一个常用的系统性能分析工具，主要用来分析系统的内存使用情况，也常用来分析CPU上下文切换和中断的次数。
# vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
1 0 90720 3960176 1036 3014980 0 0 35 85 0 1 1 0 98 0 0
0 0 90720 3959928 1036 3015004 0 0 0 24 240 358 0 0 99 0 0
0 1 90720 3959356 1036 3015068 0 0 0 34 260 390 1 0 99 0 0
0 0 90720 3959204 1036 3015088 0 0 0 23 234 340 0 0 99 0 0
0 0 90720 3960708 1036 3015088 0 0 0 609 297 429 0 0 99 0 0
0 0 90720 3960772 1036 3015112 0 0 0 140 295 410 0 0 99 0 0
0 0 90720 3960688 1036 3015164 0 0 0 36 269 406 0 0 99 0 0
r 是就绪队列的长度，也就是正在运行和等待 CPU 的进程数
b 则是处于不可中断睡眠状态的进程数
swpd 交换分区大小，一般在内存不足的情况会使用swap进行扩展
free 空闲的物理内存的大小
buff
cache
si 每秒从磁盘读入虚拟内存的大小，如果这个值大于0，表示物理内存不够用或者内存泄露了，要查找耗内存进程解决掉。
so 每秒虚拟内存写入磁盘的大小，如果这个值大于0，同上
bi 块设备每秒接收的块数量，这里的块设备是指系统上所有的磁盘和其他块设备，在处理拷贝大量数据(2-3T)的机器上看过可以达到140000/s，磁盘写入速度差不多140M每秒
bo 块设备每秒发送的块数量，读取文件，bo就要大于0。bi和bo一般都要接近0，不然就是IO过于频繁，需要调整
in 每秒CPU的中断次数，包括时间中断
cs 每秒上下文切换次数
pidstat查看每个进程的详细情况
# pidstat -w 5
05:30:32 PM UID PID cswch/s nvcswch/s Command
05:30:37 PM 0 8 18.16 0.00 rcu_sched
05:30:37 PM 0 11 0.20 0.00 watchdog/0
05:30:37 PM 0 183 4.59 0.00 kworker/3:1H
05:30:37 PM 0 388 2.40 0.00 kworker/0:1H
05:30:37 PM 0 546 0.20 0.00 irqbalance
05:30:37 PM 0 621 9.98 0.00 qemu-ga
05:30:37 PM 109 663 0.40 0.00 uml_switch
05:30:37 PM 0 1275 0.40 0.00 master
05:30:37 PM 110 1277 0.20 0.00 qmgr
05:30:37 PM 0 5896 7.39 0.00 kworker/0:0
05:30:37 PM 0 13579 8.18 0.00 sshd
05:30:37 PM 0 13766 0.20 0.00 vmstat
05:30:37 PM 0 26398 5.19 0.00 kworker/u8:1
05:30:37 PM 0 28341 6.19 0.00 kworker/u8:2
05:30:37 PM 0 28898 5.99 1.40 bash
这个结果中有两列内容是我们的重点关注对象:
- cswch自愿上下文切换: 是指进程无法获取所需资源，导致的上下文切换。比如说， I/O、内存等系统资源不足时，就会发生自愿上下文切换。
- nvcswch非自愿上下文切换: 则是指进程由于时间片已到等原因，被系统强制调度，进而发生的上下文切换。比如说，大量进程都在争抢CPU时，就容易发生非自愿上下文切换。
总结
- cswch切换变多了，说明进程都在等待资源，有可能发生了I/O等其他问题；
- nvcswch切换变多了，说明进程都在被强制调度，也就是都在争抢 CPU，说明CPU的确成了瓶颈；
频繁切换线程上下文的案列
注意：
处于waittig和blocked状态的线程都不会消耗CPU
线程频繁地挂起和唤醒需要消耗CPU, 而且代价颇大
高并发竞争锁引起的cpu升高
生成2000个线程, 利用jdk提供的LockSupport.park()不断挂起这些线程. 再使用LockSupport.unpark(t)不断地唤醒这些线程. 唤醒之后又立马挂起. 以此达到不断切换线程的目的.
jstack 命令获取到线程栈信息
"test-1-thread-6" #1522 prio=5 os_prio=0 tid=0x00007f4b7006f800 nid=0x1b67c waiting on condition [0x00007f4ac8c4a000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000006c10828c8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:210)
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
at ch.qos.logback.classic.Logger.info(Logger.java:579)
...
ReentrantLock的底层是使用AQS框架实现的。大概描述一下AQS:
- AQS有个临界变量state,当一个线程获取到state==0时, 表示这个线程进入了临界代码(获取到锁), 并原子地把这个变量值+1
- 没能进入临界区(获取锁失败)的线程, 会利用CAS的方式添加到到CLH队列尾去, 并被LockSupport.park挂起.
- 当线程释放锁的时候, 会唤醒head节点的下一个需要唤醒的线程(有些线程cancel了就不需要唤醒了)
- 被唤醒的线程检查一下自己的前置节点是不是head节点(CLH队列的head节点就是之前拿到锁的线程节点)的下一个节点,如果不是则继续挂起, 如果是的话, 与其他线程重新争夺临界变量,即重复第1步
在AQS的第2步中, 如果竞争锁失败的话, 是会使用CAS乐观锁的方式添加到队列尾的, 在并发量非常高的情况下，别线程会在这段代码自旋过久而长期占用CPU, 最终导致CPU告警
AQS中线程上下文切换
在实际的环境中, 如果临界区的代码执行时间比较短的话, 上面AQS的第3,第4步也是会导致CLH队列的线程被频繁唤醒,而又由于抢占锁失败频繁地被挂起. 因此也会带来大量的上下文切换, 消耗系统的cpu资源.
