Binary Search Tree Iterator(中序遍历)

问题概述

在项目中遇到过一个关于CPU占用率异常的问题，导致板子发热厉害，系统响应缓慢。针对这类实际问题产生原因不同，造成后果也不同，但问题分析的方式方法却殊途同归。

依次就有了分析这类问题的流程：定位问题进程，分析log，找出问题。

如下将给出一个分析此类问题的实际例子，以后遇到相似或者相关的问题都可依照此类方法进行逐步分析解决。

问题分析

• 用top命令查看问题进程

control_engine进程14094占用CPU高达891%，这个数值是进程内各个线程占用CPU的累加值。

```

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
14094 root 15 0 315m 10m 7308 S 891% 2.2 1:49.01 control_engine
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 0 2424 1060 800 R 0.3 0.2 0:00.03 top
1 root 18 0 2156 492 460 S 0.0 0.1 0:01.59 init

```

• 用top -H -p [pid]命令查看进程内各个线程占用的CPU比例

```

top -H -p 14094

ps -eLo pid,lwp,pcpu | grep 30222

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

PID USER PR NI VIRT RES SHR S %CPU MEM TIME+ COMMAND
14086 root 25 0 922m 914m 538m R 101 10.0 21:35.46 control_engine
14087 root 25 0 922m 914m 538m R 101 10.0 10:50.22 control_engine
14081 root 25 0 922m 914m 538m S 99 10.0 8:57.36 control_engine
14082 root 25 0 922m 914m 538m R 99 10.0 11:51.92 control_engine
14089 root 25 0 922m 914m 538m R 99 10.0 21:21.77 control_engine
14092 root 25 0 922m 914m 538m R 99 10.0 19:55.47 control_engine
14094 root 25 0 922m 914m 538m R 99 10.0 21:02.21 control_engine
14083 root 25 0 922m 914m 538m R 97 10.0 21:32.39 control_engine
14088 root 25 0 922m 914m 538m R 97 10.0 11:23.12 control_engine
```

• 使用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

```

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

#gcore 14094

该命令生成core文件core.14094

• 用strace命令查看系统调用和花费的时间

```

strace -T -r -c -p 14094

% time seconds usecs/call calls errors syscall

---

99.99 22.683879 3385 6702 poll
0.00 0.001132 0 6702 gettimeofday
0.00 0.000127 1 208 208 accept
0.00 0.000022 22 1 read
0.00 0.000000 0 1 write
0.00 0.000000 0 1 close
0.00 0.000000 0 14 time
0.00 0.000000 0 2 stat64
0.00 0.000000 0 4 clock_gettime
0.00 0.000000 0 7 send
0.00 0.000000 0 10 10 recvfrom

---

100.00 22.685160 13652 218 total

```

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

• 用gdb调试core文件，并线程切换到37号线程

gcore和实际的core dump时产生的core文件几乎一样，只是不能用gdb进行某些动态调试

```
(gdb) gdb control_engine 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->线程函数调用栈->函数耗时和调用统计->源代码分析

---

转载请注明来源，欢迎对文章中的引用来源进行考证，欢迎指出任何有错误或不够清晰的表达。可以在下面评论区评论，也可以邮件至 yxhlfx@163.com