昨天搞定了一个十万火急的issue,客户抱怨产品升级后系统会变慢和CPU使用率相当高,客户脾气很大,声称不尽快解决这个问题就退货,弄得我们 R&D压力很大,解决这个issue的任务分给了我,客户是南非的一个公司,由于时差问题,我只好在家远程解决问题,晚上8点半用 gotomeeting远程到客户电脑查看我们的系统,折腾了四个多小时,终于在凌晨时reproduce了这个high CPU,赶紧抓Log,用wireshark抓包,用gcore,gstack,strace和top保存了系统的相关输出。在第2天分析了这些文件后, 找到了产品的bug,代码的作者分配了10K的缓冲区,并想当然认为10K足以够用,当然99%的情况下是够用的,但是在这1%的情况下出现了问题,缓冲 区不幸被写满了,然后程序进入了死循环,导致high CPU。找到了问题了,fix就很容易了,客户的脾气也缓和了,fix很快就可以deliver给客户。反思解决问题的过程,觉得这个分析过程具有可复用 性,值得总结一下。

1.用top命令查看哪个进程占用CPU高
gateway网关进程14094占用CPU高达891%,这个数值是进程内各个线程占用CPU的累加值。

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND    
14094 root      15   315m  10m 7308 S 891%  2.2   1:49.01 gateway                                                                                 
20642 root      17   0 17784 4148 2220 S  0.5  0.8   2:39.96 microdasys                                                                                      
1679 root      18   0 10984 1856 1556 R  0.3  0.4   0:22.21 sshd                                                                                            
22563 root      18   2424 1060  800 R  0.3  0.2   0:00.03 top                                                                                             
   1 root      18   2156  492  460 S  0.0  0.1   0:01.59 init       

2.用top -H -p pid命令查看进程内各个线程占用的CPU百分比

#top -H -p 14094
top中可以看到有107个线程,但是下面9个线程占用CPU很高,下面以线程14086为主,分析其为何high CPU

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

14086 root      25   922m 914m 538m R  101 10.0  21:35.46 gateway                          

14087 root      25   0  922m 914m 538m R  101 10.0  10:50.22 gateway                           

14081 root      25   922m 914m 538m S   99 10.0   8:57.36 gateway                            

14082 root      25   922m 914m 538m R   99 10.0  11:51.92 gateway                              

14089 root      25   922m 914m 538m R   99 10.0  21:21.77 gateway                             

14092 root      25   922m 914m 538m R   99 10.0  19:55.47 gateway                               

14094 root      25   922m 914m 538m R   99 10.0  21:02.21 gateway                                

14083 root      25   922m 914m 538m R   97 10.0  21:32.39 gateway                                 

14088  root       25    922m 914m  538m R    97 10.0   11:23.12  gateway

3.使用gstack命令查看进程中各线程的函数调用栈
#gstack 14094 > gstack.log
在gstack.log中查找线程ID14086,由于函数栈会暴露函数细节,因此只显示了两个函数桢,线程ID14086对应线程号是37

Thread 37 (Thread 0x4696ab90 (LWP 14086)):
#0  0x40000410 in __kernel_vsyscall ()
#1  0x40241f33 in poll () from /lib/i686/nosegneg/libc.so.6

4.使用gcore命令转存进程映像及内存上下文

#gcore 14094
该命令生成core文件core.14094

5。用strace命令查看系统调用和花费的时间
#strace -T -r -c -p 14094

-c参数显示统计信息,去掉此参数可以查看每个系统调用话费的时间及返回值。

% time     seconds  usecs/call     calls    errors        syscall

------ ----------- ----------- --------- --------- ----------------------------

99.99   22.683879        3385      6702                     poll

0.00    0.001132               6702                    gettimeofday

0.00    0.000127                208       208         accept

0.00    0.000022          22                          read

0.00    0.000000                                    write

0.00    0.000000                                     close

0.00    0.000000                 14                   time

0.00    0.000000                                    stat64

0.00    0.000000                                   clock_gettime

0.00    0.000000                                    send

0.00    0.000000                 10        10         recvfrom

------ ----------- ----------- --------- --------- ------------------------------

100.00   22.685160                 13652       218 total

 

6.用gdb调试core文件,并线程切换到37号线程
gcore和实际的core dump时产生的core文件几乎一样,只是不能用gdb进行某些动态调试

(gdb) gdb gateway core.14094
(gdb) thread 37
[Switching to thread 37 (Thread 0x4696ab90 (LWP 14086))]#0  0x40000410 in __kernel_vsyscall ()
(gdb) where
#0  0x40000410 in __kernel_vsyscall ()
#1  0x40241f33 in poll () from /lib/i686/nosegneg/libc.so.6

可以根据详细的函数栈进行gdb调试,打印一些变量值,并结合源代码分析为何会poll调用占用很高的CPU。
因为代码涉及到公司产权,顾不在此做详细分析,需要明白的是分析的流程和使用的命令。

流程为:进程ID->线程ID->线程函数调用栈->函数耗时和调用统计->源代码分析

Linux下高cpu解决方案(转载)
标签: