【1】CPU飙升到200%以上问题汇总

NPE~

已于 2023-02-03 11:32:30 修改

阅读量4.2k

点赞数 6

分类专栏：生产问题+场景题文章标签：数据库服务器 mysql 后端运维

于 2023-02-03 10:44:09 首次发布

原文链接：https://www.cnblogs.com/crazymakercircle/p/17079410.html#autoid-h3-2-0-0

版权

生产问题+场景题专栏收录该内容

9 篇文章 9 订阅

订阅专栏

文章详细阐述了CPU使用率飙升至200%以上时，如何针对MySQL和Java进程进行问题定位和处理。在MySQL中，问题可能源于无索引的SQL查询、大量并发请求或慢查询日志；而在Java进程中，CPU飙升可能由于死循环、大量GC或对象创建。解决方案包括添加索引、使用缓存、优化代码和调整GC策略。

摘要由CSDN通过智能技术生成

【1】CPU飙升到200%以上问题汇总

CPU飙升到200%以上是生成中常见的问题

注意：

linux的cpu使用频率是根据cpu个数和核数决定的

top，然后你按一下键盘的1，这就是单个核心的负载，不然是所有核心的负载相加，自然会超过100

所有cpu使用率总和：

top

在这里插入图片描述

top # 进入交互界面
# 接下来按1，查看每个cpu占用

在这里插入图片描述

我的云服务器是2核的，因此显示的是有2个cpu

# 查询结果按照cpu使用率排
shift+P
# 按照内存占用率排序
shift+M

1 MySQL进程飙升到900%

我们日常在使用MySQL的过程中，或多或少都遇到过CPU突然过高，或者达到200%以上的情况。

数据库执行查询或数据修改操作时，系统需要消耗大量的CPU资源维护从存储系统、内存数据中的一致性。
并发量大并且大量SQL性能低的情况下，比如字段是没有建立索引，则会导致快速CPU飙升，如果还开启了慢日志记录，会导致性能更加恶化。生产上有MYSQL 飙升900% 的恶劣情况。

1.1 定位过程

使用top命令查看是否是mysqld导致还是其他原因
如果是mysqld导致，show processlist，查看session情况，确定是否有消耗资源的sql在运行
找到消耗高的sql，查看执行计划是否准确，index是否缺失，或者是数据量太大导致。

1.2 处理过程

kill掉这些线程（观察cpu使用率是否下降，通常都会下降）
进行加索引、改SQL、改内存参数

index是否缺失，如果是，则建立索引，也有可能是每个SQL消耗资源并不多，但是突然有大量的session连进导致cpu飙升，这种情况就需要跟应用一起来分析为何连接数会激增，再做出相应的调整，如：限制连接数等。

# mysql查看索引
show index from 表名;

在这里插入图片描述
3. 优化的过程，往往不是一步完成的，而是一步一步，执行一项优化措施，再观察，再优化。

1.3 真实案例

之前开发同事编写的SQL语句，就导致过线上CPU过高，MySQL的CPU使用率达到900%+，通过优化最后降低到70%~80%。下面说说个人在这个过程中的排查思路。

首先，我们要对问题定位而不是盲目的开启什么慢日志，在并发量大并且大量SQL性能低的情况下，开启慢日志无意是将MySQL推向崩溃的边缘。

当时遇到这个情况，分析了当前的数据量、索引情况、缓存使用情况。目测数据量不大，也就几百万条而已。接下来就去定位索引、缓存问题。

经过询问，发现很多查询都是走MySQL，没有用到缓存。
既然没有用到缓存，则是大量请求全部查询MySQL导致。通过下面的命令查看:

show processlist;

发现类似很多相同的SQL语句，一直处于query状态中。

select id form user where user_code = 'xxxxx';

初步分析可能是 user_code 字段没有索引导致。接着查询user表的索引情况：

show index form user;

发现这个字段是没有建立索引。增加索引之后，该条SQL查询能够正常执行。

3、没隔一会，又发生大量的请求超时问题。接着进行分析，发现是开启了慢日志查询。大量的SQL查询语句超过慢日志设置的阀值，于是将慢日志关闭之后，速度瞬间提升。CPU的使用率基本保持在300%左右。但还不是理想状态。

# 查看是否开启慢日志
show variables like "%slow_query_log%";

在这里插入图片描述

拓展：

慢查询日志，主要用来记录在 MySQL 中执行时间超过指定时间的 SQL 语句。通过慢查询日志，可以查找出哪些语句的执行效率低，以便进行优化。
慢查询日志，不能随意开启。对于需要大量IO的mysql操作，开启慢查询日志对mysql性能的影响可能远高于理论值，在亿级数据insert场景中，开启慢查询日志后insert数据慢了三倍以上。

4、紧接着将部分实时查询数据的SQL语句，都通过缓存(redis)读写实现。观察一段时间后，基本维持在了70%~80%。

总结：其实本次事故的解决很简单，就是添加索引与缓存结合使用。

不推荐在这种CPU使用过高的情况下进行慢日志的开启。因为大量的请求，如果真是慢日志问题会发生日志磁盘写入，性能贼低。
直接通过MySQL show processlist命令查看，基本能清晰的定位出部分查询问题严重的SQL语句，在针对该SQL语句进行分析。一般可能就是索引、锁、查询大量字段、大表等问题导致。
再则一定要使用缓存系统，降低对MySQL的查询频次。
对于内存调优，也是一种解决方案。

2 Java进程飙升到900%

一般来说Java 进程不做大量 CPU 运算，正常情况下，CPU 应该在 100~200% 之间，
但是，一旦高并发场景，要么走到了死循环，要么就是在做大量的 GC, 容易出现这种 CPU 飙升的情况，CPU飙升900%，是完全有可能的。

2.1 定位过程

CPU飙升问题定位的一般步骤是：

top指令查看当前占用CPU较高的进程PID；

top

查看当前进程消耗资源的线程ID（tid）：top -Hp PID

top -Hp PID

通过print命令将线程PID转为16进制，根据该16进制值去打印的堆栈日志内查询，查看该线程所驻留的方法位置。

printf "%x\n"  tid（线程id）

通过jstack命令，查看栈信息，定位到线程对应的具体代码。

# pid：java进程id	nid线程id的十六进制
jstack <pid> |grep -A 200 <nid>

在这里插入图片描述

分析代码解决问题。

2.2 处理过程：

如果是空循环，或者空自旋。

处理方式：可以使用Thread.sleep或者加锁，让线程适当的阻塞。

在循环的代码逻辑中，创建大量的新对象导致频繁GC。比如，从mysql查出了大量的数据，比如100W以上等等。

处理方式：可以减少对象的创建数量，或者，可以考虑使用对象池。

其他的一些造成CPU飙升的场景，比如 selector空轮训导致CPU飙升。

处理方式：参考Netty源码，无效的事件查询到了一定的次数，进行 selector 重建。

2.3 真实案例

最近负责的一个项目上线，运行一段时间后发现对应的进程竟然占用了700%的CPU，导致公司的物理服务器都不堪重负，频繁宕机。

那么,针对这类java进程CPU飙升的问题，我们一般要怎么去定位解决呢？

①top命令定位对应进程（号）

登录服务器，执行top命令，查看CPU占用情况，找到进程的pid

top

在这里插入图片描述
很容易发现，PID为29706的java进程的CPU飙升到700%多，且一直降不下来，很显然出现了问题。

②top -Hp定位线程（号）

使用top -Hp <pid>命令（为Java进程的id号）查看该Java进程内所有线程的资源占用情况（按shft+p按照cpu占用进行排序，按shift+m按照内存占用进行排序）

此处按照cpu排序：

top -Hp 29706

在这里插入图片描述
很容易发现，多个线程的CPU占用达到了90%多。我们挑选线程号为30309的线程继续分析。

③jstack定位问题代码

1. 线程号转换为16进制

# printf “%x\n” 命令（tid指线程的id号）将以上10进制的线程号转换为16进制：

printf "%x\n"  30309

在这里插入图片描述

转换后的结果分别为7665，由于导出的线程快照中线程的nid是16进制的，而16进制以0x开头，所以对应的16进制的线程号nid为0x7665

2. 导出线程快照

通过使用dk自带命令jstack获取该java进程的线程快照并输入到文件中

# jstack -l java进程ID > ./jstack_result.txt 
jstack -l 29706 > ./jstack_result.txt

3. 根据线程号定位具体代码

在jstack_result.txt 文件中根据线程好nid搜索对应的线程描述

# 7765为转换为16进制后的线程id
cat jstack_result.txt |grep -A 100  7665

在这里插入图片描述
根据搜索结果，判断应该是ImageConverter.run()方法中的代码出现问题

当然，这里也可以直接采用

jstack <pid> |grep -A 200 <nid>

来定位代码，例如(并非本文例子)：

$jstack 44529 |grep -A 200 ae24
“System Clock” #28 daemon prio=5 os_prio=0 tid=0x00007efc19e8e800 nid=0xae24 waiting on condition [0x00007efbe0d91000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:340)
at java.util.concurrentC.TimeUnit.sleep(TimeUnit.java:386)
at com.*.order.Controller.OrderController.detail(OrderController.java:37) //业务代码阻塞点

④分析代码解决问题

下面是ImageConverter.run()方法中的部分核心代码。

逻辑说明：

/存储minicap的socket连接返回的数据   (改用消息队列存储读到的流数据) ，设置阻塞队列长度，防止出现内存溢出
//全局变量
private BlockingQueue<byte[]> dataQueue = new LinkedBlockingQueue<byte[]>(100000);
//消费线程
@Override
public void run() {
    //long start = System.currentTimeMillis();
    while (isRunning) {
        //分析这里从LinkedBlockingQueue
        if (dataQueue.isEmpty()) {
            continue;
        }
        byte[] buffer = device.getMinicap().dataQueue.poll();
       int len = buffer.length;
}

在while循环中，不断读取堵塞队列dataQueue中的数据，如果数据为空，则执行continue进行下一次循环。
如果不为空，则通过poll()方法读取数据，做相关逻辑处理。
初看这段代码好像没什么问题，但是如果dataQueue对象长期为空的话，这里就会一直空循环，导致CPU飙升。

那么如何解决呢？

分析LinkedBlockingQueue阻塞队列的API发现：

//取出队列中的头部元素，如果队列为空则调用此方法的线程被阻塞等待，直到有元素能被取出，如果等待过程被中断则抛出InterruptedException
E take() throws InterruptedException;
//取出队列中的头部元素，如果队列为空返回null
E poll();

这两种取值的API，显然take方法更时候这里的场景。

代码修改为：

while (isRunning) {
   /* if (device.getMinicap().dataQueue.isEmpty()) {
        continue;
    }*/
    byte[] buffer = new byte[0];
    try {
        buffer = device.getMinicap().dataQueue.take();
    } catch (InterruptedException e) {
        e.printStackTrace();
    }
……
}