cpu系统态很高

guocanwen

hi，最近在我们hadoop服务器经常会出现cpu系统态很高的情况，用ps，lsof命令都会卡主,直到系统态下降下来，而且这个阶段服务不能用，jstack等命令也会失败。这种问题应该怎么定位？谢谢。一些命令的信息如下：
top - 02:39:27 up 198 days, 10:52,  2 users,  load average: 86.56, 86.86, 78.30
Tasks: 1084 total,   1 running, 1083 sleeping,   0 stopped,   0 zombie
Cpu(s): 13.4%us, 28.1%sy,  0.0%ni, 57.8%id,  0.5%wa,  0.0%hi,  0.2%si,  0.0%st
Mem:  132042880k total, 84156596k used, 47886284k free,   101608k buffers
Swap:        0k total,        0k used,        0k free, 11205992k cached

   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                           
36048 yarn      20   0 3287m  86m  20m S 299.8  0.1  88:17.25 java                                                                                                                             
167536 hdfs      20   0 9508m 6.9g  20m S 205.6  5.5   2564:04 java                                                                                                                             
36049 yarn      20   0 3286m  84m  20m S 199.7  0.1  58:52.50 java                                                                                                                             
144076 yarn      20   0 3304m 2.3g  21m S 161.0  1.8   6:28.84 java                                                                                                                             
166668 yarn      20   0 3334m 1.2g  21m S 106.8  1.0   0:32.06 java                                                                                                                             
70113 yarn      20   0 10.1g 8.3g  29m S 105.8  6.6  23491:13 java                                                                                                                             
34484 yarn      20   0 3322m 2.2g  21m S 99.8  1.7  29:37.74 java                                                                                                                              
35218 yarn      20   0 3326m 1.0g  21m S 99.8  0.8  29:32.63 java                                                                                                                              
36331 yarn      20   0 3054m  17m 7204 S 99.8  0.0  29:25.47 java                                                                                                                              
145764 yarn      20   0 3322m 679m  21m S 99.8  0.5  36:21.99 java                                                                                                                              
167980 yarn      20   0 3309m 124m  20m S 86.6  0.1   0:02.62 java                                                                                                                              
136557 yarn      20   0 3341m 957m  21m S 85.9  0.7   0:45.94 java                                                                                                                              
146174 yarn      20   0 3315m 2.2g  21m S 26.8  1.8   1:35.47 java                                                                                                                              
142868 yarn      20   0 3340m 839m  21m S 24.8  0.7  10:36.11 java                                                                                                                              
162469 yarn      20   0 3337m 2.2g  21m S 24.1  1.8   0:43.43 java                                                                                                                              
148214 yarn      20   0 3334m 2.2g  21m S 11.2  1.8   0:41.23 java                                                                                                                              
134601 yarn      20   0 3329m 2.2g  21m S 10.2  1.8   1:19.23 java                                                                                                                              
162810 yarn      20   0 3329m 2.2g  21m S  9.3  1.8   0:22.57 java                                                                                                                              
163040 yarn      20   0 3330m 2.2g  21m S  7.3  1.8   0:20.68 java                                                                                                                              
67794 yarn      20   0 3334m 650m  21m S  6.0  0.5   5:57.51 java                                                                                                                              
164884 yarn      20   0 1528m 350m  20m S  3.6  0.3   0:11.53 java                                                                                                                              
125666 yarn      20   0 3332m 622m  21m S  2.0  0.5   0:20.23 java                                                                                                                              
146707 yarn      20   0 3334m 646m  21m S  1.7  0.5   0:11.83 java                                                                                                                              
65216 yarn      20   0 3342m 656m  21m S  1.3  0.5   9:08.50 java                                                                                                                              
48602 root      20   0 1994m  73m 4840 S  1.0  0.1   3843:55 python                                                                                                                           
166506 root      20   0 15828 2152 1004 R  1.0  0.0   0:00.27 top                                                                                                                              
109079 yarn      20   0 1614m 369m  21m S  0.7  0.3   0:24.26 java                                                                                                                              
150431 yarn      20   0 1625m 380m  21m S  0.7  0.3   0:34.52 java     

============================================
iostat -xk 2 100
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          13.59    0.00   28.90    0.16    0.00   57.35

Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sdh               0.00     0.00    0.00    0.50     0.00     2.00     8.00     0.00    4.00    0.00    4.00   4.00   0.20
sdd               0.00     0.00    5.50    0.00   678.00     0.00   246.55     0.02    3.55    3.55    0.00   2.45   1.35
sdg               0.00     0.00   16.00    0.00  2200.00     0.00   275.00     0.12    7.44    7.44    0.00   4.97   7.95
sdb               0.00     0.00    3.50    0.00   512.00     0.00   292.57     0.00    0.14    0.14    0.00   0.14   0.05
sdc               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sda               0.00     0.00    0.00    3.00     0.00    12.00     8.00     0.00    0.17    0.00    0.17   0.17   0.05
sdj               0.00     0.00   18.00    0.00  2400.00     0.00   266.67     0.03    1.64    1.64    0.00   1.19   2.15
sde               0.00     0.00    0.00    5.00     0.00   142.00    56.80     0.04    8.00    0.00    8.00   1.50   0.75
sdl               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdk               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdi               0.00     0.00    9.50    0.00  1248.00     0.00   262.74     0.03    3.58    3.58    0.00   2.16   2.05
sdf               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-0              0.00     0.00    0.00    3.00     0.00    12.00     8.00     0.00    0.17    0.00    0.17   0.17   0.05
dm-1              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
dm-2              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
======================================================================
[root@xx ~]# sar -n DEV 2 100
Linux 2.6.32-431.el6.x86_64 (s-xiasha-10-2-34-21.hx)    05/08/2017      _x86_64_        (48 CPU)

02:39:44 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
02:39:46 AM        lo     15.42     15.42      3.11      3.11      0.00      0.00      0.00
02:39:46 AM      eth0      0.50      0.00      0.06      0.00      0.00      0.00      0.50
02:39:46 AM      eth1   3429.85   4040.80   3627.96   5247.96      0.00      0.00      0.00
02:39:46 AM      eth2  15020.40   3726.37  22142.00    268.66      0.00      0.00      0.00
02:39:46 AM      eth3      0.00      0.00      0.00      0.00      0.00      0.00      0.00
02:39:46 AM     bond0  18450.25   7767.16  25769.96   5516.63      0.00      0.00      0.00

02:39:46 AM     IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
02:39:48 AM        lo      6.47      6.47      1.01      1.01      0.00      0.00      0.00
02:39:48 AM      eth0      2.49      0.00      0.36      0.00      0.00      0.00      1.99
02:39:48 AM      eth1   2001.49    672.14   2801.07    315.40      0.00      0.00      0.00
02:39:48 AM      eth2   4785.07   1211.44   6692.13    447.35      0.00      0.00      0.50
02:39:48 AM      eth3      0.00      0.00      0.00      0.00      0.00      0.00      0.00
02:39:48 AM     bond0   6786.57   1883.58   9493.20    762.75      0.00      0.00      0.50
===========================================================
[root@xx ~]# vmstat 2
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
19  0      0 45197184 101608 11574808    0    0   965  1084    0    0 20  3 77  1  0
23  0      0 44817156 101608 11591660    0    0  8360  1254 58048 16982 15 28 56  0  0
17  0      0 47206472 101608 11595020    0    0  1358 12062 52115 15872 15 29 56  0  0
19  0      0 49350028 101608 11616540    0    0     4 11582 49064 12296  6 29 65  0  0
14  0      0 49311116 101608 11643376    0    0     0   712 52408 11918  6 28 66  0  0
22  0      0 51532064 101612 11695056    0    0  7894  2652 64188 16173 13 31 56  0  0
19  0      0 53186744 101612 11700556    0    0     6  3202 54924 10758 16 30 53  0  0

===============================================================
[root@xx ~]# mpstat -P ALL
Linux 2.6.32-431.el6.x86_64 (s-xiasha-10-2-34-21.hx)    05/08/2017      _x86_64_        (48 CPU)

02:40:34 AM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest   %idle
02:40:34 AM  all   19.64    0.00    2.25    0.93    0.00    0.28    0.00    0.00   76.91
02:40:34 AM    0   26.13    0.00    8.13    3.36    0.00   12.54    0.00    0.00   49.84
02:40:34 AM    1   26.16    0.00    2.83    6.39    0.00    0.37    0.00    0.00   64.24
02:40:34 AM    2   31.50    0.00    3.77    1.19    0.00    0.04    0.00    0.00   63.51
02:40:34 AM    3   25.06    0.00    2.12    1.18    0.00    0.02    0.00    0.00   71.62
02:40:34 AM    4   29.06    0.00    3.42    1.05    0.00    0.03    0.00    0.00   66.44
02:40:34 AM    5   23.12    0.00    1.89    0.86    0.00    0.02    0.00    0.00   74.11
02:40:34 AM    6   27.04    0.00    3.15    0.91    0.00    0.03    0.00    0.00   68.87
02:40:34 AM    7   21.27    0.00    1.66    0.64    0.00    0.02    0.00    0.00   76.42
02:40:34 AM    8   25.49    0.00    2.91    0.78    0.00    0.02    0.00    0.00   70.79
02:40:34 AM    9   19.66    0.00    1.49    0.49    0.00    0.01    0.00    0.00   78.34
02:40:34 AM   10   24.22    0.00    2.74    0.67    0.00    0.02    0.00    0.00   72.35
02:40:34 AM   11   18.44    0.00    1.40    0.39    0.00    0.01    0.00    0.00   79.76
02:40:34 AM   12   23.15    0.00    2.60    0.58    0.00    0.02    0.00    0.00   73.65
02:40:34 AM   13   17.58    0.00    1.32    0.32    0.00    0.01    0.00    0.00   80.77
02:40:34 AM   14   22.38    0.00    2.50    0.52    0.00    0.02    0.00    0.00   74.59
02:40:34 AM   15   16.83    0.00    1.25    0.28    0.00    0.01    0.00    0.00   81.63
02:40:34 AM   16   21.67    0.00    2.42    0.47    0.00    0.02    0.00    0.00   75.43
02:40:34 AM   17   16.21    0.00    1.23    0.25    0.00    0.01    0.00    0.00   82.30
02:40:34 AM   18   21.09    0.00    2.34    0.43    0.00    0.02    0.00    0.00   76.12
02:40:34 AM   19   15.75    0.00    1.21    0.23    0.00    0.01    0.00    0.00   82.80
02:40:34 AM   20   20.68    0.00    2.31    0.40    0.00    0.01    0.00    0.00   76.59
02:40:34 AM   21   15.45    0.00    1.18    0.22    0.00    0.01    0.00    0.00   83.14
02:40:34 AM   22   21.01    0.00    2.36    0.41    0.00    0.02    0.00    0.00   76.21
02:40:34 AM   23   15.68    0.00    1.20    0.24    0.00    0.01    0.00    0.00   82.88
02:40:34 AM   24   23.90    0.00    6.78    3.68    0.00    0.07    0.00    0.00   65.59
02:40:34 AM   25   16.09    0.00    1.81    3.63    0.00    0.01    0.00    0.00   78.45
02:40:34 AM   26   21.40    0.00    2.97    0.86    0.00    0.02    0.00    0.00   74.75
02:40:34 AM   27   17.62    0.00    3.09    1.84    0.00    0.01    0.00    0.00   77.43
02:40:34 AM   28   20.98    0.00    2.66    0.81    0.00    0.02    0.00    0.00   75.54
02:40:34 AM   29   16.30    0.00    2.39    1.72    0.00    0.01    0.00    0.00   79.57
02:40:34 AM   30   20.09    0.00    2.41    0.75    0.00    0.01    0.00    0.00   76.74
02:40:34 AM   31   15.20    0.00    1.96    1.36    0.00    0.01    0.00    0.00   81.47
02:40:34 AM   32   19.56    0.00    2.23    0.66    0.00    0.01    0.00    0.00   77.54
02:40:34 AM   33   14.73    0.00    1.68    1.02    0.00    0.01    0.00    0.00   82.56
02:40:34 AM   34   19.29    0.00    2.10    0.58    0.00    0.01    0.00    0.00   78.02
02:40:34 AM   35   14.41    0.00    1.50    0.76    0.00    0.01    0.00    0.00   83.32
02:40:34 AM   36   19.13    0.00    2.02    0.51    0.00    0.01    0.00    0.00   78.34
02:40:34 AM   37   14.18    0.00    1.38    0.57    0.00    0.01    0.00    0.00   83.86
02:40:34 AM   38   19.04    0.00    1.96    0.46    0.00    0.01    0.00    0.00   78.53
02:40:34 AM   39   14.04    0.00    1.29    0.45    0.00    0.01    0.00    0.00   84.21
02:40:34 AM   40   19.04    0.00    1.91    0.41    0.00    0.01    0.00    0.00   78.63
02:40:34 AM   41   13.93    0.00    1.25    0.37    0.00    0.01    0.00    0.00   84.45
02:40:34 AM   42   19.09    0.00    1.90    0.37    0.00    0.01    0.00    0.00   78.62
02:40:34 AM   43   13.93    0.00    1.21    0.32    0.00    0.01    0.00    0.00   84.54
02:40:34 AM   44   19.07    0.00    1.88    0.35    0.00    0.01    0.00    0.00   78.69
02:40:34 AM   45   14.05    0.00    1.20    0.28    0.00    0.01    0.00    0.00   84.46
02:40:34 AM   46   19.15    0.00    1.88    0.35    0.00    0.01    0.00    0.00   78.61
02:40:34 AM   47   13.98    0.00    1.20    0.26    0.00    0.01    0.00    0.00   84.55
   

ericzc0423

有规律吗，是周期性的吗？strace可以运行吗？有装jconsole/jmx之类的监控工具吗？是否有尝试过profiler？

guocanwen

回复 2# ericzc0423

间歇性抽风，过会就好。dmesg有些信息，不过这些栈信息每台机器都不一样。INFO: task java:50332 blocked for more than 120 seconds.
      Tainted: G           --------------- H  2.6.32-431.el6.x86_64 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
java          D 0000000000000003     0 50332  25742 0x00000080
ffff880eff619cf0 0000000000000086 0000000000000000 0000000000000200
0000000000000001 0000000000000000 0000000000000000 0000000000000000
ffff8806ce138638 ffff880eff619fd8 000000000000fbc8 ffff8806ce138638
Call Trace:
[<ffffffff814c58ca>] ? inet_recvmsg+0x5a/0x90
[<ffffffff81529f85>] rwsem_down_failed_common+0x95/0x1d0
[<ffffffff8109f24b>] ? __remove_hrtimer+0x3b/0xb0
[<ffffffff8152a116>] rwsem_down_read_failed+0x26/0x30
[<ffffffff8128e854>] call_rwsem_down_read_failed+0x14/0x30
[<ffffffff81529614>] ? down_read+0x24/0x30
[<ffffffff8104a92e>] __do_page_fault+0x18e/0x480
[<ffffffff811d0c45>] ? ep_remove+0xa5/0xc0
[<ffffffff812263c6>] ? security_file_permission+0x16/0x20
[<ffffffff8152d45e>] do_page_fault+0x3e/0xa0
[<ffffffff8152a815>] page_fault+0x25/0x30
INFO: task java:50334 blocked for more than 120 seconds.
      Tainted: G           --------------- H  2.6.32-431.el6.x86_64 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
java          D 0000000000000009     0 50334  25742 0x00000080
ffff881798537cf0 0000000000000086 0000000000000000 ffff881798537cb8
0000000000000282 ffff881798537c88 ffff881798581650 ffff881798537cb8
ffff8819e18cf098 ffff881798537fd8 000000000000fbc8 ffff8819e18cf098
Call Trace:
[<ffffffffa01c6d13>] ? xfs_trans_free_item_desc+0x33/0x40 [xfs]
[<ffffffffa01c6e57>] ? xfs_trans_free_items+0x87/0xb0 [xfs]
[<ffffffff81529f85>] rwsem_down_failed_common+0x95/0x1d0
[<ffffffff8152a116>] rwsem_down_read_failed+0x26/0x30
[<ffffffff8128e854>] call_rwsem_down_read_failed+0x14/0x30
[<ffffffff81529614>] ? down_read+0x24/0x30
[<ffffffff8104a92e>] __do_page_fault+0x18e/0x480
[<ffffffff81282705>] ? _atomic_dec_and_lock+0x55/0x80
[<ffffffff811aaa20>] ? mntput_no_expire+0x30/0x110
[<ffffffff8118a7d1>] ? __fput+0x1a1/0x210
[<ffffffff8152d45e>] do_page_fault+0x3e/0xa0
[<ffffffff8152a815>] page_fault+0x25/0x30

ericzc0423

jconsole, jprofiler做一下再说，dmesg中只是Java block-120s，没有太多实用的信息。