java应用导致cpu占用过高问题分析及解决办法

admin

java应用导致cpu占用过高问题分析及解决办法
, V$ @( _. n8 P" `( B3 i! Y0 P1 k
2 b2 K; \2 z: [! R$ J. E

主要介绍了java应用cpu占用过高问题分析及解决方法，具有一定参考价值，需要的朋友可以参考下。 使用jstack分析java程序cpu占用率过高的问题

1，使用jps查找出java进程的pid，如 55001

2 y, c( B! T0 V( r1 [

[devops@ops_prod_flink_01 neo4j]$ jps

60226 Jps

55001 CommunityEntryPoint

6 ?1 {! A" r# U6 `, E6 g

[devops@ops_prod_flink_01 ~]$ top -p 55001 -H

2、使用 top -p 55001 -H 观察该进程中所有线程的CPU占用

top - 10:05:07 up 537 days, 16:08,  2 users,  load average: 0.10, 2.92, 9.17

Threads:  67 total,   0 running,  67 sleeping,   0 stopped,   0 zombie

%Cpu(s):  1.2 us,  0.8 sy,  0.0 ni, 98.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st

KiB Mem : 24636208 total, 10156628 free,  2782836 used, 11696744 buff/cache

KiB Swap:  2097148 total,  2053116 free,    44032 used. 20841700 avail Mem

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

55033 devops    20   0 6395992 692476  22340 S  1.0  2.8   0:03.13 java                                                                                                         

55034 devops    20   0 6395992 692476  22340 S  0.7  2.8   0:03.90 java                                                                                                         

55035 devops    20   0 6395992 692476  22340 S  0.3  2.8   0:03.36 java                                                                                                         

55036 devops    20   0 6395992 692476  22340 S  0.3  2.8   0:02.46 java                                                                                                         

55098 devops    20   0 6395992 692476  22340 S  0.3  2.8   0:00.58 java                                                                                                         

57048 devops    20   0 6395992 692476  22340 S  0.3  2.8   0:00.14 java                                                                                                         

55001 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55006 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:03.62 java                                                                                                         

55007 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.08 java                                                                                                         

55008 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.08 java                                                                                                         

55009 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.08 java                                                                                                         

55010 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.07 java                                                                                                         

55011 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.07 java                                                                                                         

55012 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.09 java                                                                                                         

55013 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.09 java                                                                                                         

55014 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.07 java                                                                                                         

55015 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.18 java                                                                                                         

55016 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55017 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55018 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55019 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55020 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55021 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java                                                                                                         

55022 devops    20   0 6395992 692476  22340 S  0.0  2.8   0:00.00 java      

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

3，找出CPU消耗较多的线程id，如55033，将55033转换为16进制0xd6f4，注意是小写哦

4，使用jstack 55001|grep -A 10 0xd6f4来查询出具体的线程状态

[devops@ops_prod_flink_01 neo4j]$ jstack 55001 |grep -A 10 0xd6f4

"VM Thread" os_prio=0 tid=0x00007fae7c1fb000 nid=0xd6f4 runnable

"Gang worker#0 (Parallel GC Threads)" os_prio=0 tid=0x00007fae7c024800 nid=0xd6df runnable

"Gang worker#1 (Parallel GC Threads)" os_prio=0 tid=0x00007fae7c026800 nid=0xd6e0 runnable

"Gang worker#2 (Parallel GC Threads)" os_prio=0 tid=0x00007fae7c028000 nid=0xd6e1 runnable

"Gang worker#3 (Parallel GC Threads)" os_prio=0 tid=0x00007fae7c02a000 nid=0xd6e2 runnable

"Gang worker#4 (Parallel GC Threads)" os_prio=0 tid=0x00007fae7c02c000 nid=0xd6e3 runnable

通过这些线程状态便可基本定位问题之所在。

方法1

1.jps 获取Java进程的PID。

2.jstack pid >> java.txt 导出CPU占用高进程的线程栈。

3.top -H -p PID 查看对应进程的哪个线程占用CPU过高。

4.echo “obase=16; PID” | bc 将线程的PID转换为16进制,大写转换为小写。

5.在第二步导出的Java.txt中查找转换成为16进制的线程PID。找到对应的线程栈。

6.分析负载高的线程栈都是什么业务操作。优化程序并处理问题。

方法2

1.使用top 定位到占用CPU高的进程PID top 通过ps aux | grep PID命令

2.获取线程信息，并找到占用CPU高的线程 ps -mp pid -o THREAD,tid,time | sort -rn

3.将需要的线程ID转换为16进制格式 printf “%x\n” tid

4.打印线程的堆栈信息 jstack pid |grep tid -A 30

* ^& C6 _( _6 r; y# v: H& b

admin

1.执行“top”命令：查看所有进程占系统CPU的排序。极大可能排第一个的就是咱们的java进程（COMMAND列）。PID那一列就是进程号。
6 _3 E5 J# o% O, k, [6 T9 Q
2.执行“top -Hp 进程号”命令：查看java进程下的所有线程占CPU的情况。

) q; f5 ?' D: K' S- p3.执行“printf "%x\n 10"命令 ：后续查看线程堆栈信息展示的都是十六进制，为了找到咱们的线程堆栈信息，咱们需要把线程号转成16进制。例如,printf "%x\n 10-》打印：a，那么在jstack中线程号就是0xa.

* E+ {9 s5 q+ T- x4 h4.执行 “jstack 进程号 | grep 线程ID”  查找某进程下-》线程ID（jstack堆栈信息中的nid）=0xa的线程状态。如果“"VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable”，第一个双引号圈起来的就是线程名，如果是“VM Thread”这就是虚拟机GC回收线程了

5.执行“jstat -gcutil 进程号 统计间隔毫秒 统计次数（缺省代表一致统计）”，查看某进程GC持续变化情况，如果发现返回中FGC很大且一直增大-》确认Full GC! 也可以使用“jmap -heap 进程ID”查看一下进程的堆内从是不是要溢出了，特别是老年代内从使用情况一般是达到阈值(具体看垃圾回收器和启动时配置的阈值)就会进程Full GC。

6.执行“jmap -dump:format=b,file=filename 进程ID”，导出某进程下内存heap输出到文件中。可以通过eclipse的mat工具查看内存中有哪些对象比较多,飞机票：Eclipse Memory Analyzer（MAT），内存泄漏插件，安装使用一条龙；

admin

1. 使用top查看系统的资源占用情况
) M1 h- {0 B+ Itop
连到生产服务器，执行top命令，发现双核的CPU几乎全被一个PID为5739的进程给用掉了，99.2%的用户空间（也可以叫用户态）消耗，极有可能是出现了死循环。
Java应用造成us高的主要原因是线程一直处于可运行（Runnable）状态，通常这些线程在执行无阻塞操作、循环、正则或纯粹的计算等任务，另一个可能造成us高的原因是频繁GC。
& T( Y2 o0 y' W6 M$ k
6 }. V, z( N0 B, U2 m2. 使用ps命令查看进程对应的是哪个程序
8 O% [  I/ x( W! Q3 @4 K9 Wps
可以看出，罪魁祸首是ccbs。这里也可以使用jps命令。

4 ?( |" [- T) r$ y( R# h  o/ _3. 使用top -p [PID] -H 观察该进程中所有线程的资源占用
. H5 a6 k& G# I执行 top -p 5739 -H
9 x0 A* Y+ |; A% M' C, J$ btop -p -H

参数        说明
6 p0 Q" ?4 f' S% `-p        需要监控的进程id
-H        显示每个线程的情况，否则就是进程的总状态
4 J$ v7 ?  G  I3 d/ O5 W发现若干线程实时CPU占用率（%CPU）较高，并且处理机使用时间（TIME+）非常长，6146线程实际占有处理机852分钟40.44秒，那么如何知道这个线程正在干嘛呢？我猜测Java这么成熟的平台，肯定有可以解决问题的工具，毕竟这样的问题很多人都会遇到。
. m/ L/ h* x% L/ s
9 e7 Q, B$ B8 v; m3 ^4.使用jstack查看线程快照
1 K# E2 z- P% S2 y' o% t! S- n通过在搜索引擎中查找，我得知通过jstack可以生成java虚拟机当前时刻的线程快照。
执行jstack 5739 | grep -A 100 nid=0x1802
jstack
5 C4 ?( h: V4 H# i0 `3 I* M, jjstack后面的参数是PID的值，nid的含义是操作系统映射的线程id，可以通过nid的值过滤上面占用CPU较高的6146线程，线程id需要转成十六进制，并且字母要小写。
通过观察输出，可以看到线程长期处于可运行状态，直接根据堆栈信息找到对应的代码。
# V' `, M/ {- E) {
5.解决bug
% L; |& Y. H/ A8 Z& C. i/ Kcode
这部分代码并不是我写的，很明显这种写法非常不好，一旦serviceAddressType的值不在那三种范围内，就会产生死循环，我重写了这里的逻辑，问题解决。

总结
2 i( [! n) {8 ]7 I% ?1 l2 u任何数据都可能出错，程序逻辑应该充分考虑出现问题的可能。
; Q6 B$ b, X7 n: H我们遇到的问题，很可能别人也遇到过，要擅于使用搜索引擎。

admin

1.内存消耗过大，导致Full GC次数过多
  F% I, r- [: ~) _7 L% P执行步骤1-5：
$ ^8 w6 {7 Q$ h( L3 Z
7 X- F" T% ~' U  k& i& ]多个线程的CPU都超过了100%，通过jstack命令可以看到这些线程主要是垃圾回收线程-》上一节步骤2
. ]/ q! u2 t/ X3 t5 |7 V. o0 W通过jstat命令监控GC情况，可以看到Full GC次数非常多，并且次数在不断增加。--》上一节步骤5
- R# J0 y3 Z! ~$ T确定是Full GC,接下来找到具体原因：
6 D- C$ ~: ~; _0 C( z  o
) L1 r1 {' [8 k) h$ n生成大量的对象，导致内存溢出-》执行步骤6，查看具体内存对象占用情况。
内存占用不高，但是Full GC次数还是比较多，此时可能是代码中手动调用 System.gc()导致GC次数过多，这可以通过添加 -XX:+DisableExplicitGC来禁用JVM对显示GC的响应。
1 M$ L% I7 T" `% E- C2.代码中有大量消耗CPU的操作，导致CPU过高，系统运行缓慢；
执行步骤1-4：在步骤4jstack，可直接定位到代码行。例如某些复杂算法，甚至算法BUG，无限循环递归等等。
) E! s- U8 ^4 R" f% `% K( M
. X& ?/ [: g& b+ \7 J6 x
6 \( M/ p+ }1 Y. t+ t. ?
3.由于锁使用不当，导致死锁。
# i% z1 t5 p4 r! A6 }8 z8 p8 A执行步骤1-4： 如果有死锁，会直接提示。关键字：deadlock.步骤四，会打印出业务死锁的位置。
9 w: N* M7 a: X$ `8 [- f
" w7 q4 g1 J* s3 U  h( y造成死锁的原因：最典型的就是2个线程互相等待对方持有的锁。


# g+ _2 ~/ ^: o# @) e8 F
4.随机出现大量线程访问接口缓慢。
代码某个位置有阻塞性的操作，导致该功能调用整体比较耗时，但出现是比较随机的；平时消耗的CPU不多，而且占用的内存也不高。
6 g4 i1 e7 {4 [5 a4 m
5 ^& n1 g+ f2 u/ W) U思路：
0 X" ?1 U6 L4 {: r( l/ n
首先找到该接口，通过压测工具不断加大访问力度，大量线程将阻塞于该阻塞点。
& N  s5 Y  A' H' i$ ?4 Y
; _% d; }. J% A/ ^1 `5 m6 z; L执行步骤1-4：
0 z8 N1 Z% ^1 H" n+ e& x6 @+ j8 l- C
. }# }1 j' j1 @7 H: \复制代码
"http-nio-8080-exec-4" #31 daemon prio=5 os_prio=31 tid=0x00007fd08d0fa000 nid=0x6403 waiting on condition [0x00007000033db000]

* o" k" G/ b& z. d: G" m   java.lang.Thread.State: TIMED_WAITING (sleeping)-》期限等待

; U/ x# x3 V; d2 Y    at java.lang.Thread.sleep(Native Method)
) p1 ]. z/ B$ q; L, Z7 S
2 }# W: e7 _; B& F  x0 g5 I    at java.lang.Thread.sleep(Thread.java:340)
% C' f  Z5 L, M" M
    at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)

& g7 e# K+ D6 e: l3 P    at com.*.user.controller.UserController.detail(UserController.java:18)-》业务代码阻塞点
复制代码
如上图，找到业务代码阻塞点，这里业务代码使用了TimeUnit.sleep()方法，使线程进入了TIMED_WAITING(期限等待)状态。关于线程状态，不理解的飞机票：Thread类源码剖析

/ z" n6 j0 |" a/ E5.某个线程由于某种原因而进入WAITING状态，此时该功能整体不可用，但是无法复现；
执行步骤1-4：jstack多查询几次，每次间隔30秒，对比一直停留在parking 导致的WAITING状态的线程。例如CountDownLatch倒计时器，使得相关线程等待->AQS(AbstractQueuedSynchronizer AQS框架源码剖析)->LockSupport.park()。
  ?: M# B2 z6 v5 J  K# k
复制代码
) _, a# F  G+ S" T% I"Thread-0" #11 prio=5 os_prio=31 tid=0x00007f9de08c7000 nid=0x5603 waiting on condition [0x0000700001f89000]   
java.lang.Thread.State: WAITING (parking) ->无期限等待
- U; e- t& [. J$ Uat sun.misc.Unsafe.park(Native Method)   
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:304)   
at com.*.SyncTask.lambda$main$0(SyncTask.java:8)-》业务代码阻塞点
2 e% d" v- l5 Y+ q. Zat com.*.SyncTask$$Lambda$1/1791741888.run(Unknown Source)   
at java.lang.Thread.run(Thread.java:748)
! R9 \4 K; ~1 ]7 r  {- {3 v% _复制代码
$ P2 Z; H4 c3 u8 a3 H

admin

问题
1、无限循环的while会导致CPU使用率飙升吗？
0 c! i! f' y0 q$ |4 W* Q' p, l2、经常使用Young GC会导致CPU占用率飙升吗？
3、具有大量线程的应用程序的CPU使用率是否较高？
1 a6 }% e' `5 N3 ?( w& f- a; P4、CPU使用率高的应用程序的线程数是多少？
5、处于BLOCKED状态的线程会导致CPU使用率飙升吗？
6、分时操作系统中的CPU是消耗 us还是 sy？

2 n& k) V0 c# T, a7 K思路
1.如何计算CPU使用率？
CPU％= 1 - idleTime / sysTime * 100
4 q1 r7 J/ p' }' G2 U. f, P
idleTime：CPU空闲的时间

3 Z4 Q3 [7 t7 N, x, w: f0 U1 dsysTime：CPU处于用户模式和内核模式的时间总和

' z8 I, d+ R4 M8 B2.与CPU使用率有关的是什么？
人们常说，计算密集型程序的CPU密集程度更高。

那么，JAVA应用程序中的哪些操作更加CPU密集？
# I) g, I8 X% R# w7 R1 A% P1 d$ C
以下列出了常见的CPU密集型操作：
9 d8 Q# `% v& e5 V  ^
" s: n: V* f, W, m! `6 ]1、频繁的GC; 如果访问量很高，可能会导致频繁的GC甚至FGC。当调用量很大时，内存分配将如此之快以至于GC线程将连续执行，这将导致CPU飙升。
9 R$ c& N5 `# j6 K5 |2、序列化和反序列化。稍后将给出一个示例：当程序执行xml解析时，调用量会增加，从而导致CPU变满。
* u8 c8 D8 |% R, X; {2 N/ o3、序列化和反序列化;
4、正则表达式。我遇到了正则表达式使CPU充满的情况; 原因可能是Java正则表达式使用的引擎实现是NFA自动机，它将在字符匹配期间执行回溯。
& H7 R1 p& H4 [. c( X1 ?4 q. ^5、线程上下文切换; 有许多已启动的线程，这些线程的状态在Blocked（锁定等待，IO等待等）和Running之间发生变化。当锁争用激烈时，这种情况很容易发生。
6、有些线程正在执行非阻塞操作，例如 while(true)语句。如果在程序中计算需要很长时间，则可以使线程休眠。
  G- E: S( I( m6 b2 ]# _
4 B" Q# i/ G9 r7 K6 ^3、CPU是否与进程和线程相关？
现在，分时操作系统使用循环方式为进程调度分配时间片。如果进程正在等待或阻塞，那么它将不会使用CPU资源。线程称为轻量级进程，并共享进程资源。因此，线程调度在CPU中也是分时的。但在Java中，我们使用JVM进行线程调度。因此，通常，线程调度有两种模式：时间共享调度和抢占式调度。
! I; O3 o  D. a  ?( ~) s9 e7 d
& s, u6 D3 e+ O; y% X5 u答案
3 |9 L9 ]6 W, i. |1、while的无限循环会导致CPU使用率飙升吗？
是。

! j; d% h8 d, w首先，无限循环将调用CPU寄存器进行计数，此操作将占用CPU资源。那么，如果线程始终处于无限循环状态，CPU是否会切换线程？
) X* ]8 f/ K  a! @8 y& k, ~9 a
1 d- }% S% L7 b7 h$ j7 P( f) G除非操作系统时间片到期，否则无限循环不会放弃占用的CPU资源，并且无限循环将继续向系统请求时间片，直到系统没有空闲时间来执行任何其他操作。整编：微信公众号，搜云库技术团队，ID：souyunku
. V. T% K5 R0 r% i4 M) o' d4 S
% E3 R' W( D8 z0 U1 {, N- fstackoverflow中也提出了这个问题：为什么无意的无限循环增加了CPU的使用？
8 M' e5 \% Z( ^! d! F
+ H( _5 D* }  |$ Q5 K$ h+ p, i% hhttps://stackoverflow.com/questi ... ncrease-the-cpu-use

) U* B. G; N- \* J3 t2、频繁的Young GC会导致CPU占用率飙升吗？
是。

( \  h% {3 Z: vYoung GC本身就是JVM用于垃圾收集的操作，它需要计算内存和调用寄存器。因此，频繁的Young GC必须占用CPU资源。
* Z5 J. h. w: f
: u" @% J# Z! ]6 ~) t' _让我们来看一个现实世界的案例。for循环从数据库中查询数据集合，然后再次封装新的数据集合。如果内存不足以存储，JVM将回收不再使用的数据。因此，如果所需的存储空间很大，您可能会收到CPU使用率警报。
' v! b& S: H5 J- ]$ w; T
3、具有大量线程的应用程序的CPU使用率是否较高？
不时。
; V1 ], y1 D+ E
如果通过jstack检查系统线程状态时线程总数很大，但处于Runnable和Running状态的线程数不多，则CPU使用率不一定很高。

我遇到过这样一种情况：系统线程的数量是1000+，其中超过900个线程处于BLOCKED和WAITING状态。该线程占用很少的CPU。
0 D5 U( _  U; ~0 k  a
* d* n; D5 f; W4 p5 ~7 w3 i: @但是大多数情况下，如果线程数很大，那么常见的原因是大量线程处于BLOCKED和WAITING状态。

( B2 r7 z6 Q) ^3 x; L% r6 S. H* h4、对于CPU占用率高的应用程序，线程数是否较大？
$ G, `7 S; e' @! _1 p/ q不是。
+ D5 B7 b- w! H7 ^$ A) Q
高CPU使用率的关键因素是计算密集型操作。如果一个线程中有大量计算，则CPU使用率也可能很高。这也是数据脚本任务需要在大规模集群上运行的原因。
8 y# e- H3 @8 ?' c5 q9 K& `
' a6 V2 k+ }! }9 P3 a5 r9 Q5、处于BLOCKED状态的线程是否会导致CPU占用率飙升？
  e+ O  U* T. j" \3 L& Y7 z# x不会。

CPU使用率的飙升更多是由于上下文切换或过多的可运行状态线程。处于阻塞状态的线程不一定会导致CPU使用率上升。

6、如果分时操作系统中CPU的值 us或 sy值很高，这意味着什么？
您可以使用命令查找CPU的值 us和 sy值 top，如以下示例所示：


& b/ `/ k: ^, {: k& R: kus：用户空间占用CPU的百分比。简单来说，高我们是由程序引起的。通过分析线程堆栈很容易找到有问题的线程。整编：微信公众号，搜云库技术团队，ID：souyunku

sy：内核空间占用CPU的百分比。当sy为高时，如果它是由程序引起的，那么它基本上是由于线程上下文切换。

经验
1 i( T8 U6 j/ v1 U如何找出CPU使用率高的原因？下面简要描述分析过程。

如果发现应用程序服务器的CPU使用率很高，请首先检查线程数，JVM，系统负载等参数，然后使用这些参数来证明问题的原因。其次，使用jstack打印堆栈信息并使用工具分析线程使用情况（建议使用fastThread，一个在线线程分析工具）。
- U) c" N+ |3 x  d, P+ h) N: J, C0 H
$ z" y6 y# _) `! |& D1 k: x; I" ~以下是一个真实案例：
1 J) |/ W- O& b( T8 U
- i6 @3 J5 M: {一天晚上，我突然收到一条消息，说CPU使用率达到了100％。然后我用jstack导出了线程栈信息。


进一步检查日志：

代码语言：javascript
3 s! }8 r9 X& }: E1 f8 R1 g复制
9 a; Y$ u% p# M7 E! K. x  tonsumer_ODC_L_nn_jmq919_1543834242875 - priority:10- threadid:0x00007fbf7011e000- nativeid:0x2f093- state:RUNNABLE
3 p1 [; [# {3 O& e6 `8 `4 d! PstackTrace:
- j  P! x1 s7 i! i: Djava.lang.Thread.State:RUNNABLE
at java.lang.Object.hashCode(NativeMethod)
at java.util.HashMap.hash(HashMap.java:362)
" d- S/ M9 ~' e: a. Kat java.util.HashMap.getEntry(HashMap.java:462)
at java.util.HashMap.containsKey(HashMap.java:449)
at com.project.order.odc.util.XmlSerializableTool.deSerializeXML(XMLSerializableTool.java:100)
at com.project.plugin.service.message.resolver.impl.OrderFinishMessageResolver.parseMessage(OrderFinishMessageResolver.java:55)
& |6 W, Z8 o% z) |5 }9 w( w7 I: Tat com.project.plugin.service.message.resolver.impl.OrderFinishMessageResolver.parseMessage(OrderFinishMessageResolver.java:21)
at com.project.plugin.service.message.resolver.impl.AbstractResolver.resolve(AbstractResolver.java:28)
at com.project.plugin.service.jmq.AbstractListener.onMessage(AbstractListener.java:44)
5 e9 e: e$ w- p8 s2 ~, ]; W) J+ Y现在通过这个日志找到了问题：用于反序列化MQ消息实体的方法导致CPU使用率飙升