线上Java程序导致服务器CPU占用率过高的问题排除过程

博文转至:http://www.jianshu.com/p/3667157d63bb,博文更好效果看原版,转本博文的目的就算是个书签吧,需要时候可以定位原文学习

1、故障现象

客服同事反馈平台系统运行缓慢,网页卡顿严重,多次重启系统后问题依然存在,使用top命令查看服务器情况,发现CPU占用率过高。

2、CPU占用过高问题定位

2.1、定位问题进程

使用top命令查看资源占用情况,发现pid为14063的进程占用了大量的CPU资源,CPU占用率高达776.1%,内存占用率也达到了29.8%

[[email protected] ~]$ top
top - 14:51:10 up 233 days, 11:40,  7 users,  load average: 6.85, 5.62, 3.97
Tasks: 192 total,   2 running, 190 sleeping,   0 stopped,   0 zombie
%Cpu(s): 97.3 us,  0.3 sy,  0.0 ni,  2.5 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 16268652 total,  5114392 free,  6907028 used,  4247232 buff/cache
KiB Swap:  4063228 total,  3989708 free,    73520 used.  8751512 avail Mem
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                               

14063 ylp       20   0 9260488 4.627g  11976 S 776.1 29.8 117:41.66 java
2.2、定位问题线程

使用ps -mp pid -o THREAD,tid,time命令查看该进程的线程情况,发现该进程的多个线程占用率很高

[[email protected] ~]$ ps -mp 14063 -o THREAD,tid,time
USER     %CPU PRI SCNT WCHAN  USER SYSTEM   TID     TIME
ylp       361   -    - -         -      -     - 02:05:58
ylp       0.0  19    - futex_    -      - 14063 00:00:00
ylp       0.0  19    - poll_s    -      - 14064 00:00:00
ylp      44.5  19    - -         -      - 14065 00:15:30
ylp      44.5  19    - -         -      - 14066 00:15:30
ylp      44.4  19    - -         -      - 14067 00:15:29
ylp      44.5  19    - -         -      - 14068 00:15:30
ylp      44.5  19    - -         -      - 14069 00:15:30
ylp      44.5  19    - -         -      - 14070 00:15:30
ylp      44.5  19    - -         -      - 14071 00:15:30
ylp      44.6  19    - -         -      - 14072 00:15:32
ylp       2.2  19    - futex_    -      - 14073 00:00:46
ylp       0.0  19    - futex_    -      - 14074 00:00:00
ylp       0.0  19    - futex_    -      - 14075 00:00:00
ylp       0.0  19    - futex_    -      - 14076 00:00:00
ylp       0.7  19    - futex_    -      - 14077 00:00:15

从输出信息可以看出,14065~14072之间的线程CPU占用率都很高

2.3、查看问题线程堆栈

挑选TID为14065的线程,查看该线程的堆栈情况,先将线程id转为16进制,使用printf "%x\n" tid命令进行转换

[[email protected] ~]$ printf "%x\n" 14065
36f1

再使用jstack命令打印线程堆栈信息,命令格式:jstack pid |grep tid -A 30

[[email protected] ~]$ jstack 14063 |grep 36f1 -A 30
"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa35001e800 nid=0x36f1 runnable
"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa350020800 nid=0x36f2 runnable
"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fa350022800 nid=0x36f3 runnable
"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fa350024000 nid=0x36f4 runnable
"GC task thread#4 (ParallelGC)" prio=10 tid=0x00007fa350026000 nid=0x36f5 runnable
"GC task thread#5 (ParallelGC)" prio=10 tid=0x00007fa350028000 nid=0x36f6 runnable
"GC task thread#6 (ParallelGC)" prio=10 tid=0x00007fa350029800 nid=0x36f7 runnable
"GC task thread#7 (ParallelGC)" prio=10 tid=0x00007fa35002b800 nid=0x36f8 runnable
"VM Periodic Task Thread" prio=10 tid=0x00007fa3500a8800 nid=0x3700 waiting on condition 

JNI global references: 392

从输出信息可以看出,此线程是JVM的gc线程。此时可以基本确定是内存不足或内存泄露导致gc线程持续运行,导致CPU占用过高。
所以接下来我们要找的内存方面的问题

3、内存问题定位

3.1、使用jstat -gcutil命令查看进程的内存情况
[[email protected] ~]$ jstat -gcutil 14063 2000 10

  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT
  0.00   0.00 100.00  99.99  26.31     42   21.917   218 1484.830 1506.747
  0.00   0.00 100.00  99.99  26.31     42   21.917   218 1484.830 1506.747
  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484
  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484
  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484
  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484
  0.00   0.00 100.00  99.99  26.31     42   21.917   219 1496.567 1518.484
  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355
  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355
  0.00   0.00 100.00  99.99  26.31     42   21.917   220 1505.439 1527.355

从输出信息可以看出,Eden区内存占用100%,Old区内存占用99.99%,Full GC的次数高达220次,并且频繁Full GC,Full GC的持续时间也特别长,平均每次Full GC耗时6.8秒(1505.439/220)。根据这些信息,基本可以确定是程序代码上出现了问题,可能存在不合理创建对象的地方

3.2、分析堆栈

使用jstack命令查看进程的堆栈情况

[[email protected] ~]$ jstack 14063 >>jstack.out

把jstack.out文件从服务器拿到本地后,用编辑器查找带有项目目录并且线程状态是RUNABLE的相关信息,从图中可以看出ActivityUtil.java类的447行正在使用HashMap.put()方法

Paste_Image.png

3.3、代码定位

打开项目工程,找到ActivityUtil类的477行,代码如下:

Paste_Image.png

找到相关同事了解后,这段代码会从数据库中获取配置,并根据数据库中remain的值进行循环,在循环中会一直对HashMap进行put操作。

查询数据库中的配置,发现remain的数量巨大

Paste_Image.png

至此,问题定位完毕。

时间: 2024-10-20 06:48:44

线上Java程序导致服务器CPU占用率过高的问题排除过程的相关文章

记一次线上Java程序导致服务器CPU占用率过高的问题排除过程

https://blog.csdn.net/u013991521/article/details/52781423 1.故障现象 客服同事反馈平台系统运行缓慢,网页卡顿严重,多次重启系统后问题依然存在,使用top命令查看服务器情况,发现CPU占用率过高. 2.CPU占用过高问题定位 2.1.定位问题进程 使用top命令查看资源占用情况,发现pid为14063的进程占用了大量的CPU资源,CPU占用率高达776.1%,内存占用率也达到了29.8% [ylp@ylp-web-01 ~]$ top t

[转帖]Java性能检测工具-记录一次通过jstack排查Linux服务器CPU占用率很高的实践

Java性能检测工具-记录一次通过jstack排查Linux服务器CPU占用率很高的实践 https://www.jianshu.com/p/d4e31301ba2e 一.问题描述 Linux服务器的配置是4核16G,将war包部署到tomcat后,启动tomcat,发现内存占用率不高,但是CPU一直高达100%:浏览器输入相关url也无法访问该项目,且tomcat的进程一直存在,程序的配置什么的都没问题啊,一头雾水......通过top命令查看服务器的性能状况如下: [[email prote

Java内存、CPU占用率过高

windows下揪出java程序占用cpu很高的线程 并找到问题代码 死循环线程代码 linux下查找java进程占用CPU过高原因 Java 占用CPU使用率很高的分析 记一次线上Java程序导致服务器CPU占用率过高的问题排除过程

云服务器 ECS Linux 系统 CPU 占用率较高问题排查思路

https://help.aliyun.com/knowledge_detail/41225.html?spm=5176.7841174.2.2.ifP9Sc 注意:本文相关配置及说明已在 CentOS 6.5 64 位操作系统中进行过测试.其它类型及版本操作系统配置可能有所差异,具体情况请参阅相应操作系统官方文档. 如果云服务器 ECS Linux 系统的 CPU 持续跑高,则会对系统稳定性和业务运行造成影响.本文对 CPU 占用率较高问题的排查分析做简要说明. CPU 负载查看方法 使用 v

zprofiler三板斧解决cpu占用率过高问题

zprofiler三板斧解决cpu占用率过高问题  九居 浏览 171 2015-04-08 14:11:58 发表于:JVM性能与调试平台 zprofiler 上周五碰到了一个线上机器cpu占用率过高的问题.问题本身比较简单,但是定位过程中动用了多个zprofiler的主要功能,感觉是一个很好的介绍使用zprofiler定位此类问题流程的案例. 在开始使用zprofiler之前,先使用perf确认瓶颈点是否在native中.(以下操作需要root权限,需要pe协助操作)如果线上服务器没有安装p

12月9日 - SQL server CPU占用率过高的分析过程

故障描述:今日二中的服务器CPU占用率一直非常高,几乎接近100%   分析步骤: 需要使用 SQL server自带的 Profiler工具

一次服务器CPU占用率高的定位分析

背景 通过性能监控发现上线服务器cpu某核占用率已经达到了100%,而且是由我们的某个核心服务导致的.幸亏由于我们的服务进程由多个相同worker(线程)调度承担的,所以除了CPU占用率高之外,并没有对服务造成影响.随着上次我们找到那个吃IO的罪犯,这次我们要追捕的是潜伏在团体中的特务,更加惊险刺激哟! 系统环境 用top命令很容易定位到是谁占用CPU最高. 以我们的这个业务进程(imDevServer)举例,为什么说这货是个潜伏者呢?因为这是个多线程的进程,我们要知道实际上占用cpu的最小单位

线上服务器CPU占用率高如何排查定位

环境 centos7 1核2GB Java8 模拟cpu占用高 新建一个名为jvm-learn的springboot项目 模拟代码如下 import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.web.bind.annotation.GetMapping; imp

Redis CPU占用率过高问题定位处理

以Redis作为缓存的项目在即将发布时碰到一个奇怪的问题:新布署的软件包在进行压力测试时Redis服务器的CPU利用率竟然达到了100%.于是回退代码,对比即将发布的包与老包的差异,同时分别在对应的Redis服务器上运行info Commandstats命令进行抓包分析,发现如下现象: 如上所示上面二个截图为布署老包时1分钟之内Redis服务器执行的所有命令: 在这里我们可以清晰的看到1分钟之内Redis 收到的ping命令次数大概为:6237822-5903451=334371: 布署新包后R