CPU狂飙900%,如何分析,怎么定位,怎么溯源处理

CPU飙升200% 以上是生产容易发生的场景

场景:1:MySQL进程飙升900%

评估:

大家在使用MySQL过程,想必都有遇到过CPU突然过高,或者达到200%以上的情况。

数据库执行查询或数据修改操作时,系统需要消耗大量的CPU资源维护从存储系统、内存数据中的一致性。

并发量大并且大量SQL性能低的情况下,比如字段是没有建立索引,则会导致快速CPU飙升,如果还开启了慢日志记录,会导致性能更加恶化。生产上有MYSQL 飙升900% 的恶劣情况。

定位:

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

处理:

  • kill 掉这些线程(同时观察 cpu 使用率是否下降), 一般来说,肯定要 kill 掉这些线程(同时观察 cpu 使用率是否下降),等进行相应的调整(比如说加索引、改 sql、改内存参数)之后,再重新跑这些 SQL。

  • 进行相应的调整(比如说加索引、改 sql、改内存参数)

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

  • 优化的过程,往往不是一步完成的,而是一步一步,执行一项优化措辞,再观察,再优化。

    • 分析当前的数据量、索引情况、缓存使用情况。目测数据量不大,也就几百万条而已。接下来就去定位索引、缓存问题。
      1、经过询问,发现很多查询都是走MySQL,没有用到缓存。
      2、既然没有用到缓存,则是大量请求全部查询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%左右。但还不是理想状态。

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

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

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

场景2:Java进程飙升900%

一般来说Java 进程不做大量 CPU 运算,正常情况下,CPU 应该在 100~200% 之间,

但是,一旦高并发场景,要么走到了死循环,要么就是在做大量的 GC, 容易出现这种 CPU 飙升的情况,CPU飙升900%,是完全有可能的。

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

1、首先通过top指令查看当前占用CPU较高的进程PID;
2、查看当前进程消耗资源的线程PID:top -Hp PID
3、通过print命令将线程PID转为16进制,根据该16进制值去打印的堆栈日志内查询,查看该线程所驻留的方法位置。
4、通过jstack命令,查看栈信息,定位到线程对应的具体代码。
5、分析代码解决问题。

处理:

1、如果是空循环,或者空自旋。

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

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

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

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

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

采用top命令定位进程

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

top
image.png

很容易发现,PID为29706的java进程的CPU飙升到700%多,且一直降不下来,很显然出现了问题。

使用top -Hp命令定位线程

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

此处按照cpu排序:

top -Hp 23602
image.png

多个线程的CPU占用达到了90%多。我们挑选线程号为30309的线程继续分析。

使用jstack命令定位代码

1.线程号转换5为16进制
printf “%x\n” 命令(tid指线程的id号)将以上10进制的线程号转换为16进制:

printf  "%x\n"  30309
image.png

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

2.采用jstack命令导出线程快照

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

jstack -l 进程ID > ./jstack_result.txt 

命令(为Java进程的id号)来获取线程快照结果并输入到指定文件。

jstack -l 29706 > ./jstack_result.txt

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

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

cat jstack_result.txt |grep -A 100  7665
image.png

根据搜索结果,判断应该是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)  //业务代码阻塞点

分析代码解决问题
重启项目后,测试发现项目运行稳定,对应项目进程的CPU消耗占比不到10%。


image.png
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,547评论 6 477
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,399评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,428评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,599评论 1 274
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,612评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,577评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,941评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,603评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,852评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,605评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,693评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,375评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,955评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,936评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,172评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 43,970评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,414评论 2 342

推荐阅读更多精彩内容