一次 CPU 飙高异常的处理

一次 CPU 飙高异常的处理

某天,同事告诉我说我在公司负责的一个服务 CPU 占用过高,达到 700% 多(多核 CPU),猜测可能是 gc 比较频繁,让我调一下堆大小,调整过后重新部署,发现 CPU 使用率降至正常水平(6% 左右)。

过了几天想起来这个事,登上服务器看下服务是否正常,发现 CPU 使用率又到了 500% 多,于是就通过一些工具命令排查问题。

初步排查是否是 gc 问题

通过 jstat -gc pid 命令查看 gc 情况,发现进行了 20w 多次 young gc,full gc 只有不到 10 次,于是怀疑是 gc 问题。

再次使用 jstat -gc pid 50 20(每 50ms 打印一次,一共打印 20 次) 命令,发现每秒进行 2 次 young gc,两次 gc 之间都会分配大量的新生代内存(由于当时没有截图,所以不放图了),但是老年代空间几乎没有变化。从打印的结果来看,每次新生代新分配内存都超过 200M,于是确定是某段代码频繁创建对象,导致新生代内存不够,发生 young gc。

由于之前没有过类似的经验,打算根据《深入理解Java虚拟机》这本书里对 jvm 内存问题排查的描述,想着 dump 出内存镜像,再观察新生代的对象,判断具体是哪些对象占用内存过多。但是没有实际进行过这样的操作,而且是要从线上服务 dump heap,所以没有自己动手,等 mentor 有时间的时候一起排查。

动手排查问题

我向 mentor 说了服务的情况和我的想法,但是 mentor 说不一定是 gc 问题,然后 Google 了一下如何排查 CPU 占用过高的问题,发现很多文章都是用同一个方法,就是接下来我要说的方法,找出占用 CPU 过高的线程,再看这些线程在执行哪段代码。

其实这个方法之前查的时候也看到了,但是潜意识里认为是 gc 问题,而且感觉没有直接看内存镜像来得直观,所以也没有动手试。

具体操作步骤如下:

  1. jps 命令查看当前运行的 Java 进程,找到异常服务的进程 ID(pid)
  2. top -Hp pid 查看该进程所有线程的运行情况,找到占用 CPU 过高的线程 pid
  3. printf %x pid 打印出 pid 的 16 进制值(jstack 命令结果中的线程 ID 为 nid,且用 16 进制表示)
  4. jstack pid 命令查看线程快照,根据上一步得到的 16 进制值找到具体的线程,就能知道这个进程在执行什么代码了

通过上述步骤,定位到问题是一个工具类的某个方法,对返回结果进行高亮词的标记,开发者使用了 commons-lang 包的 IntRange 类,每找到一个高亮词就会创建一个 IntRange 对象,并且将找到的高亮词进行合并(比如要高亮的词是 Java 和 JavaScript,如果目标字符串有 JavaScript,那么最后就会高亮整个 JavaScript 字符串)、排序(方便下次合并),并且在合并的时候,合并后的结果也创建了一个新的 IntRange 对象,这样就会频繁创建对象。排序使用 JDK 自带的 Collections.sort() 方法,每找到一个词都会合并,也会消耗大量的 CPU 资源。

定位到问题后,对这段代码进行了优化,不使用 IntRange 对象标记找到的高亮词,而是创建一个和目标字符串的大小相同的数组,找到要高亮的词以后把在字符串中的下标映射在数组的下标值设置为 1,这样就不需要合并高亮范围和排序,避免了创建大量对象,整体复杂度大大降低。

排查完问题进行优化以后,CPU 使用率又降到了 6% 左右,连续观察 3 天一切指标正常。

总结

其实这并不是一个 gc 问题导致的 CPU 使用率过高,gc 频繁只是因为创建了太多的对象,并且 gc 线程并没有占用太多的 CPU 资源,根本原因还是代码的时间复杂度太高,CPU 使用率接近 100% 的那几个线程都是在执行高亮代码。

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

推荐阅读更多精彩内容