系统稳定性—CPU占用过高问题排查及解决

一、CPU利用率与CPU负载的区别

提到CPU利用率，就必须理解时间片。什么是CPU时间片？我们现在所使用的Windows、Linux、Mac OS都是“多任务操作系统”，就是说他们可以“同时”运行多个程序，比如一边打开Chrome浏览器浏览网页还能一边听音乐。但是，实际上一个CPU内核在同一时刻只能干一件事，那操作系统是如何实现“多任务”的呢？大概的方法是让多个进程轮流使用CPU一小段时间，由于这个“一小段时间”很短(在linux上为5ms-800ms之间)，用户感觉不到，就好像是几个程序同时在运行了。上面提到的“一小段时间”就是我们所说的CPU时间片，CPU的现代分时多任务操作系统对CPU都是分时间片使用的。

CPU使用率，就是程序对CPU时间片的占用情况，即\(CPU使用率 = CPU时间片被程序使用的时间 / 总时间\)。比如A进程占用10ms，然后B进程占用30ms，然后空闲60ms，再又是A进程占10ms，B进程占30ms，空闲60ms，如果在一段时间内都是如此，那么这段时间内的CPU占用率为40%。
CPU利用率显示的是程序在运行期间实时占用的CPU百分比。大多数操作系统的CPU占用率分为用户态CPU使用率和系统态CPU使用率。用户态CPU使用率是指执行应用程序代码的时间占总CPU时间的百分比。相比而言，系统态CPU使用率是指应用执行操作系统调用的时间占总CPU时间的百分比。系统态的CPU使用率高意味着共享资源有竞争或者I/O设备之间有大量的交互。
CPU负载显示的是一段时间内正在使用和等待使用CPU的平均任务数。简单理解，一个是CPU的实时使用情况，一个是CPU的当前以及未来一段时间的使用情况。举例来说：如果我有一个程序它需要一直使用CPU的运算功能，那么此时CPU的使用率可能达到100%，但是CPU的工作负载则是趋近于“1”，因为CPU仅负责一个工作嘛！如果同时执行这样的程序两个呢？CPU的使用率还是100%，但是工作负载则变成2了。所以也就是说，CPU的工作负载越大，代表CPU必须要在不同的工作之间进行频繁的工作切换。无论CPU的利用率是高是低，跟后面有多少任务在排队(CPU负载)没有必然关系。

如果单核CPU的话，负载达到1就代表CPU已经达到满负荷的状态了，超过1，后面的进行就需要排队等待处理了。如果是多核多CPU，假设现在服务器是2个CPU，每个CPU有2个核，那么总负载不超过4都没什么问题。

可以通过uptime、w命令查看CPU平均负载，使用top命令还能看到CPU负载总体使用率以及各个进程占用CPU的比例。

640.png

查看物理CPU个数

cat /proc/cpuinfo| grep “physical id”| sort | uniq| wc -l

查看每个物理CPU中core的个数(即核数)

cat /proc/cpuinfo| grep “cpu cores” | uniq

查看逻辑CPU的个数

cat /proc/cpuinfo| grep “processor”| wc -l

二、CPU负载很高，利用率却很低

CPU负载很高，利用率却很低，说明处于等待状态的任务很多，负载越高，代表可能很多僵死的进程。通常这种情况是IO密集型的任务，大量任务在请求相同的IO，导致任务队列堆积。

生产环境造成CPU利用率低负载高的具体场景常见的有如下几种。

2.1 场景一：磁盘读写请求过多就会导致大量I/O等待

进程在cpu上面运行需要访问磁盘文件，这个时候CPU会向内核发起调用文件的请求，让内核去磁盘取文件，这个时候CPU会切换到其他进程或者空闲，这个任务就会转换为不可中断睡眠状态。当这种读写请求过多就会导致不可中断睡眠状态的进程过多，从而导致负载高，CPU低的情况。

2.2 场景二：MySQL中存在没有索引的语句或存在死锁等情况

我们都知道MySQL的数据是存储在硬盘中，如果需要进行sql查询，需要先把数据从磁盘加载到内存中。当在数据特别大的时候，如果执行的sql语句没有索引，就会造成扫描表的行数过大导致I/O阻塞，或者是语句中存在死锁，也会造成I/O阻塞，从而导致不可中断睡眠进程过多，导致负载过大。

同样，可以先通过top命令观察，假设发现现在确实是高负载低使用率。

6403.png

然后，再通过命令ps -aux查看是否存在状态为D的进程，这个状态指的就是不可中断的睡眠状态的进程。处于这个状态的进程无法终止，也无法自行退出，只能通过恢复其依赖的资源或者重启系统来解决。以下图中没有D状态的进程。

6404.png

Linux上进程的五种状态

  • R(task_running)：可执行状态，只有在该状态的进程才可能在CPU上运行。而同一时刻可能有多个进程处于可执行状态。
  • S(task_interruptible)：可中断的睡眠状态，处于这个状态的进程因为等待某某事件的发生(比如等待socket连接、等待信号量)，而被挂起。
  • D(task_uninterruptible)：不可中断的睡眠状态，进程处于睡眠状态，但是此刻进程是不可中断的。task_uninterruptible状态存在的意义就在于，内核的某些处理流程是不能被打断的。
  • T(task_stopped/task_traced)：暂停状态或跟踪状态。
  • Z(task_dead - exit_zombie)：退出状态，进程成为僵尸进程。进程已终止，但进程描述还在，直到父进程调用wait4()系统调用后释放。

三、CPU负载很低，利用率却很高

这表示CPU的任务并不多，但是任务执行的时间很长，大概率就是你写的代码本身有问题，通常是计算密集型任务，生成了大量耗时短的计算任务。

怎么排查？直接top命令找到CPU使用率最高的进程，定位到去看看就行了。如果代码没有问题，那么过段时间CPU使用率就会下降的。

四、CPU利用率达到100%排查

  1. 通过top找到CPU占用率高的进程

6401.png

  1. 通过top -Hp pid命令查看CPU占比靠前的线程ID

6402.png

  1. 再把线程ID转化为16进制，printf “0x%x\n” 74317，得到0x1224d
  2. 通过命令jstack 72700 | grep ‘0x1224d’ -C5 --color找到有问题的代码

注意：jstack的对象是java进程的PID，而不是java线程的PID。

线上除了CPU外，还有可能是其他问题，可参考系统稳定性—线上常见问题排查

五、示例

先来看一段代码:

package com.jvm;

import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class JvmCpuTest {
    
    private static ExecutorService service = Executors.newFixedThreadPool(5);
    private static Object lock = new Object();
    
    public static class TaskTest implements Runnable {
        @Override
        public void run() {
            synchronized (lock){
                long sum = 0L;
                while(true){
                    sum +=1;
                }
            }
        }
    }

    public static void main(String[] args) {
        TaskTest taskTest = new TaskTest();
        service.execute(taskTest);
    }
}

将这段代码上传到linux服务器，并且使用nohup java JvmCpuTest &运行

使用top命令可以看到cpu被打满了

知道了进程的PID，如何找到进程下是哪个线程呢?可以使用命令top -Hp 26964

可以看到，cpu占用最多的线程是26976这个线程id，接下来就是使用jstack命令来查看程序的所有堆栈信息，但是，这里需要有一个注意的点，26876这个是一个十进制的，使用jstack看到的nid是十六进制，所以我们需要转换，可以使用printf "%x\n"这个命令

接下来使用jstack -l 26964打印堆栈信息

2024-06-08 12:17:36
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.281-b09 mixed mode):
 
"Attach Listener" #10 daemon prio=9 os_prio=0 tid=0x00007f006c001000 nid=0xc7f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"DestroyJavaVM" #9 prio=5 os_prio=0 tid=0x00007f00a0009800 nid=0x6955 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"pool-1-thread-1" #8 prio=5 os_prio=0 tid=0x00007f00a00f0000 nid=0x6960 runnable [0x00007f008b0ef000]
   java.lang.Thread.State: RUNNABLE
	at JvmCpuTest$TaskTest.run(JvmCpuTest.java:14)
	- locked <0x00000000f59dfcf0> (a java.lang.Object)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
 
   Locked ownable synchronizers:
	- <0x00000000f59e0ed0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
 
"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007f00a00d4800 nid=0x695e runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f00a00b9800 nid=0x695d waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f00a00b6800 nid=0x695c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f00a00b5000 nid=0x695b runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
 
   Locked ownable synchronizers:
	- None
 
"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f00a0082000 nid=0x695a in Object.wait() [0x00007f008b6f5000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f5988ee0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
	- locked <0x00000000f5988ee0> (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)
 
   Locked ownable synchronizers:
	- None
 
"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f00a007d800 nid=0x6959 in Object.wait() [0x00007f008b7f6000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000f5986c00> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	- locked <0x00000000f5986c00> (a java.lang.ref.Reference$Lock)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
 
   Locked ownable synchronizers:
	- None
 
"VM Thread" os_prio=0 tid=0x00007f00a0074000 nid=0x6958 runnable 
 
"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f00a001e800 nid=0x6956 runnable 
 
"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f00a0020800 nid=0x6957 runnable 
 
"VM Periodic Task Thread" os_prio=0 tid=0x00007f00a00d7800 nid=0x695f waiting on condition 
 
JNI global references: 5

从下面的信息中就可以看到问题其实是出现在JvmCpuTest.java的14行左右，这里给出的是14行，但是实际情况是14行的附近，结合代码来看一下就很容易问题

"pool-1-thread-1" #8 prio=5 os_prio=0 tid=0x00007f00a00f0000 nid=0x6960 runnable [0x00007f008b0ef000]
   java.lang.Thread.State: RUNNABLE
	at JvmCpuTest$TaskTest.run(JvmCpuTest.java:14)
	- locked <0x00000000f59dfcf0> (a java.lang.Object)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

参考文章

posted @ 2022-04-24 11:27  夏尔_717  阅读(2829)  评论(0)  编辑  收藏  举报