搜文章
推荐 原创 视频 Java开发 iOS开发 前端开发 JavaScript开发 Android开发 PHP开发 数据库 开发工具 Python开发 Kotlin开发 Ruby开发 .NET开发 服务器运维 开放平台 架构师 大数据 云计算 人工智能 开发语言 其它开发
Lambda在线 > LoveInLog > 快速定位生产故障问题-JVM进程CPU占用率高于100%

快速定位生产故障问题-JVM进程CPU占用率高于100%

LoveInLog 2018-03-01

古语有云:人在江湖漂,哪有不挨刀。

这几年作为技术leader处理过的线上紧急问题,掐指一算应该有不下10次吧(说多了都是泪啊~~)。所以挡刀救火也是leader的必备技能!本文主要分享遇到“JVM进程CPU占用率超100%”时如何快速定位原因。

  1. 生产故障-JVM进程CPU占用率高于100% 某日,运维同学反馈生产环境有故障,某个JVM进程CPU负载一直居高不下。登入服务器用 top -c 命令查看如下:

 
   
   
 
  1. top - 00:37:39 up 48 days, 10:41,  5 users,  load average: 3.34, 3.18, 3.10

  2. Tasks: 166 total,   1 running, 165 sleeping,   0 stopped,   0 zombie

  3. Cpu0  :  0.7%us,  0.3%sy,  0.0%ni, 99.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

  4. Cpu1  :100.0%us,  0.0%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

  5. Cpu2  :  1.3%us,  0.3%sy,  0.0%ni, 98.3%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

  6. Cpu3  :  0.3%us,  0.0%sy,  0.0%ni, 99.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

  7. Mem:  16332280k total, 15744336k used,   587944k free,   200632k buffers

  8. Swap:  8191992k total,   408724k used,  7783268k free,  7201204k cached

  9.  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                        

  10. 9702 bb    20   0 2898m 348m  14m S 100.6  2.2   01:47.18 java -server -Xms512M -Xmx512M -Xmn192M -Xss256k -XX:PermSize=64M -XX:MaxPermSize=128M -verbose:

  11. ...

从输出结果看,CPU load 达到3以上,服务器是4核机器,负载已经不低了。进程ID为9720的进程CPU占用率超过100%。

  1. 定位故障的思路 首先找出问题进程内CPU占用率高的线程 再通过线程栈信息找出该线程当时在运行的问题代码段

  2. 定位故障的步骤 3.1 用top命令查找进程内导致CPU占用率高的线程 先祭出第一招, top命令加上 -H -b 两个选项:-H 可以查看由某个进程启动的所有线程,-b 选项指定以批处理模式输出结果 。具体命令如下:

 
   
   
 
  1. $ top -Hbp 9702

  2. top - 00:38:54 up 48 days, 10:43,  5 users,  load average: 0.81, 0.36, 0.16

  3. Tasks:  38 total,   1 running,  37 sleeping,   0 stopped,   0 zombie

  4. Cpu(s):  3.5%us,  1.4%sy,  0.0%ni, 94.5%id,  0.3%wa,  0.0%hi,  0.2%si,  0.0%st

  5. Mem:  16332280k total, 15744500k used,   587780k free,   200632k buffers

  6. Swap:  8191992k total,   408724k used,  7783268k free,  7201392k cached

  7.  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                        

  8. 10007 bb    20   0 2898m 348m  14m R 100.5  2.2   1:41.31 java                                                                                            

  9. 9702 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.00 java                                                                                            

  10. 9705 bb    20   0 2898m 348m  14m S  0.0  2.2   0:06.44 java                                                                                            

  11. 9706 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.11 java                                                                                            

  12. 9707 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.11 java                                                                                            

  13. 9708 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.11 java                                                                                            

  14. 9709 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.10 java                                                                                            

  15. 9710 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.00 java                                                                                            

  16. 9711 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.07 java                                                                                            

  17. 9712 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.03 java                                                                                            

  18. 9713 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.03 java                                                                                            

  19. 9714 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.00 java                                                                                            

  20. 9715 bb    20   0 2898m 348m  14m S  0.0  2.2   0:00.00 java                                                                                            

  21. 9716 bb    20   0 2898m 348m  14m S  0.0  2.2   0:05.60 java

输出结果里的PID其实是线程ID,可以看到线程ID为10007的线程CPU占用率为100.5%,它就是罪魁祸首。上面的命令可以再优化下:查出CPU占用率超过某个值的所有线程,例如超过50%,如下:

 
   
   
 
  1. top -Hbp 9702 | awk '/java/ && $9>50'

3.2 用JVM命令 jstack 精确定位出问题的代码段 第二招,用jstack 命令dump出线程栈信息,可以直接定位到出问题的代码段。这里也分两步。第一步把上面的线程ID 10007 转化为十六进制:

 
   
   
 
  1. $ printf "%x\n" 10007

  2. 2717

因为jstack输出的线程栈信息中,线程ID是以十六进制展示的。

第二步使用命令 jstack $pid | grep “线程id” 把信息打印出来:

 
   
   
 
  1. $ jstack 9702 | grep '2717' -A 30

  2. "http-nio-9092-exec-1" daemon prio=10 tid=0x00007f3a90014800 nid=0x2717 runnable [0x00007f3afc72a000]

  3.   java.lang.Thread.State: RUNNABLE

  4.    at com.bb.apigateway.filter.pre.SignatureTokenFilter.run(SignatureTokenFilter.java:44)

  5.    at com.netflix.zuul.ZuulFilter.runFilter(ZuulFilter.java:112)

  6.    at com.netflix.zuul.FilterProcessor.processZuulFilter(FilterProcessor.java:197)

  7.    at com.netflix.zuul.FilterProcessor.runFilters(FilterProcessor.java:161)

  8.    at com.netflix.zuul.FilterProcessor.preRoute(FilterProcessor.java:136)

  9.    at com.netflix.zuul.ZuulRunner.preRoute(ZuulRunner.java:105)

  10.    at com.netflix.zuul.http.ZuulServlet.preRoute(ZuulServlet.java:125)

  11.    at com.netflix.zuul.http.ZuulServlet.service(ZuulServlet.java:74)

  12.    at org.springframework.web.servlet.mvc.ServletWrappingController.handleRequestInternal(ServletWrappingController.java:158)

  13.    at org.springframework.cloud.netflix.zuul.web.ZuulController.handleRequestInternal(ZuulController.java:43)

  14.    at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:147)

  15.    at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:50)

  16.    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:961)

  17.    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:895)

  18.    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:967)

  19.    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:869)

  20.    at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)

  21.    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:843)

  22.    at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)

  23.    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292)

  24.    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

  25.    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)

  26.    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

  27.    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

  28.    at org.springframework.boot.actuate.autoconfigure.EndpointWebMvcAutoConfiguration$ApplicationContextHeaderFilter.doFilterInternal(EndpointWebMvcAutoConfiguration.java:261)

  29.    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)

  30.    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)

  31.    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)

  32.    at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:115)

下面这行就是出问题的业务代码,根据实际情况修复BUG即可

 
   
   
 
  1. com.bb.apigateway.filter.pre.SignatureTokenFilter.run(SignatureTokenFilter.java:44)

  1. 小结 思路:

找出CPU占用率高的进程 找出问题进程内CPU占用率高的线程 通过线程栈信息找出该线程当时在运行的问题代码段 实施要点:

top -Hbp ‘pid’ 定位问题线程 jstack ‘pid’ | grep ‘thread_id’ 找出问题代码


版权声明:本站内容全部来自于腾讯微信公众号,属第三方自助推荐收录。《快速定位生产故障问题-JVM进程CPU占用率高于100%》的版权归原作者「LoveInLog」所有,文章言论观点不代表Lambda在线的观点, Lambda在线不承担任何法律责任。如需删除可联系QQ:516101458

文章来源: 阅读原文

相关阅读

关注LoveInLog微信公众号

LoveInLog微信公众号:loveinglog

LoveInLog

手机扫描上方二维码即可关注LoveInLog微信公众号

LoveInLog最新文章

精品公众号随机推荐