摘要:

本文首先介绍了不可中断睡眠状态产生的原因,以及僵尸进程相关的概念,并通过一个简单的案例分析了cpu iowait 升高的 性能定位分析问题的场景。

不可中断睡眠状态

不可中断状态睡眠(Uninterruptible Sleep),一般表示进程正在跟硬件交互,并且交互过程不允许被其他进程或中断打断。

不可中断状态,其实是为了保证进程数据与硬件状态一致,并且正常情况下,不可中断状态在很短时间内就会结束。所以,短时的不可中断状态进程,一般可以忽略。

但如果系统或硬件发生了故障,进程可能会在不可中断状态保持很久,甚至导致系统中出现大量不可中断进程。此时就需要排查系统是不是出现了 I/O 等性能问题?

僵尸进程

正常情况下,当一个进程创建了子进程后,应该通过系统调用 wait() 或者 waitpid() 等待子进程结束,回收子进程的资源;而子进程在结束时,会向它的父进程发送 SIGCHLD 信号,所以,父进程还可以注册 SIGCHLD 信号的处理函数,异步回收资源。如果父进程没进行资源回收,或是子进程执行太快,父进程还没来得及处理子进程状态,子进程就已经提前退出,那这时的子进程就会变成僵尸进程。

正常,僵尸进程持续的时间都比较短,在父进程回收它的资源后就会消亡;或者在父进程退出后,由 init 进程回收后也会消亡。一旦父进程没有处理子进程的终止,还一直保持运行状态,那么子进程就会一直处于僵尸状态。

大量的僵尸进程会用尽 PID 进程号,导致新进程不能创建,所以这种情况一定要避免。

僵尸进程的问题相对容易排查:使用 pstree 找出父进程后,去查看父进程的代码,检查 wait() / waitpid() 的调用,或是 SIGCHLD 信号处理函数的注册就行了。

案例

yine@ubuntu:~$ ps -aux | grep app

root 425349 0.0 0.0 2488 460 ? Ss+ 22:30 0:00 /app

root 425385 7.1 0.0 0 0 ? Z+ 22:30 0:01 [app]

root 425386 4.8 0.0 0 0 ? Z+ 22:30 0:00 [app]

root 425388 26.6 0.0 0 0 ? Z+ 22:31 0:03 [app]

root 425389 25.7 0.0 0 0 ? Z+ 22:31 0:03 [app]

root 425390 21.5 3.2 68028 65708 ? R+ 22:31 0:01 /app

root 425391 12.8 3.2 68028 65708 ? R+ 22:31 0:01 /app

yine 425397 0.7 0.0 8900 732 pts/7 S+ 22:31 0:00 grep --color=auto app

root 425398 4.0 3.2 68028 65700 ? D+ 22:31 0:00 /app

root 425399 3.5 3.2 68028 65696 ? D+ 22:31 0:00 /app

s 表示这个进程是一个会话的领导进程,而 + 表示前台进程组。

进程组和会话。它们用来管理一组相互关联的进程,意思其实很好理解。

进程组表示一组相互关联的进程,比如每个子进程都是父进程所在组的成员;

而会话是指共享同一个控制终端的一个或多个进程组。

top 观察平均负载

top - 22:41:36 up 3 min, 1 user, load average: 3.20, 1.32, 0.15

Tasks: 371 total, 1 running, 340 sleeping, 0 stopped, 30 zombie

平均负载正在升高,同时僵尸进程数量在增多, 同时各个cpu 的iowait 升高

dstat 监控

dstat 1 20

You did not select any stats, using -cdngy by default.

--total-cpu-usage-- -dsk/total- -net/total- ---paging-- ---system--

usr sys idl wai stl| read writ| recv send| in out | int csw

2 13 72 12 0| 744M 45k| 0 0 |1755B 10k|1269 1068

6 22 64 9 0|1218M 0 | 0 0 | 0 0 |1758 922

4 28 42 26 0|1593M 0 | 0 0 | 0 0 |2367 1275

5 31 35 30 0|1664M 0 | 129B 0 | 0 0 |2180 1018

6 27 39 28 0|1629M 0 | 0 70B| 0 0 |2391 961

0 1 99 0 0| 45M 0 | 0 0 | 0 0 | 329 468

4 21 56 19 0|1199M 0 | 0 0 | 0 0 |1796 1005

4 27 41 29 0|1643M 0 | 0 0 | 0 0 |2372 1138

5 31 33 31 0|1637M 0 | 120B 60B| 0 0 |2157 912

5 26 38 30 0|1670M 0 | 0 0 | 0 0 |2601 1028

0 0 100 0 0| 0 0 | 0 0 | 0 0 | 210 361

可发现 iowait 在升高的时候,磁盘读请求在升高。

pidstat 找出磁盘读的进程 确定时app 进程在进行磁盘读

pidstat -d 1 10

Linux 5.4.0-54-generic (ubuntu) 12/07/2020 _x86_64_ (4 CPU)

10:56:18 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:19 PM 0 3217 -1.00 -1.00 -1.00 25 app

10:56:19 PM 0 3218 -1.00 -1.00 -1.00 35 app

10:56:19 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:20 PM 0 3217 -1.00 -1.00 -1.00 104 app

10:56:20 PM 0 3218 -1.00 -1.00 -1.00 82 app

10:56:20 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:21 PM 0 3217 -1.00 -1.00 -1.00 95 app

10:56:21 PM 0 3218 -1.00 -1.00 -1.00 106 app

10:56:21 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:22 PM 0 3217 -1.00 -1.00 -1.00 71 app

10:56:22 PM 0 3218 -1.00 -1.00 -1.00 83 app

10:56:22 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:23 PM 0 3217 -1.00 -1.00 -1.00 17 app

10:56:23 PM 0 3218 -1.00 -1.00 -1.00 19 app

10:56:23 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:24 PM 0 3219 -1.00 -1.00 -1.00 30 app

10:56:24 PM 0 3220 -1.00 -1.00 -1.00 39 app

10:56:24 PM UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command

10:56:25 PM 0 3219 -1.00 -1.00 -1.00 100 app

10:56:25 PM 0 3220 -1.00 -1.00 -1.00 85 app

4.perf 调用查看 app 调用链情况

发现有直接磁盘读的调用: blkdev_direct_IO

$ perf record -g

$ perf report

+ 8.86% 8.36% kworker/0:1H-kb [kernel.kallsyms] [k] mpt_put_msg_frame ▒

- 7.52% 0.00% app [kernel.kallsyms] [k] entry_SYSCALL_64_aft▒

entry_SYSCALL_64_after_hwframe ▒

- do_syscall_64 ▒

- 7.43% __x64_sys_read ▒

- ksys_read ▒

- 7.43% vfs_read ▒

- 7.43% __vfs_read ▒

new_sync_read ▒

blkdev_read_iter ▒

- generic_file_read_iter ▒

- 7.43% blkdev_direct_IO ▒

- 7.43% __blkdev_direct_IO ▒

+ 5.68% submit_bio ▒

+ 1.34% bio_iov_iter_get_pages ▒

+ 7.52% 0.00% app [kernel.kallsyms] [k] do_syscall_64 ▒

+ 7.52% 0.00% app libc-2.31.so [.] __libc_start_main ▒

- 7.52% 0.00% app app [.] main ▒

- main ▒

+ 7.43% read ▒

+ 7.43% 0.00% app libc-2.31.so [.] read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] __x64_sys_read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] ksys_read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] vfs_read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] __vfs_read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] new_sync_read ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] blkdev_read_iter ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] generic_file_read_it▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] blkdev_direct_IO ▒

+ 7.43% 0.00% app [kernel.kallsyms] [k] __blkdev_direct_IO

app 的确在通过系统调用 sys_read() 读取数据。并且从 new_sync_read 和 blkdev_direct_IO 能看出,进程正在对磁盘进行直接读,也就是绕过了系统缓存,每个读请求都会从磁盘直接读,这就可以解释我们观察到的 iowait 升高了。

优化

直接读写磁盘,对 I/O 敏感型应用(比如数据库系统)是很友好的,因为你可以在应用中,直接控制磁盘的读写。但在大部分情况下,最好还是通过系统缓存来优化磁盘 I/O,因此一般的应用删除 O_DIRECT 这个选项可以。

DIR *dirptr = opendir("/dev/");

perror("Failed to open dir");

int fd = open(disk, O_RDONLY | O_DIRECT | O_LARGEFILE, 0755);

perror("failed to open disk");

总结

虽然这个案例是磁盘 I/O 导致了 iowait 升高,不过, iowait 高不一定代表 I/O 有性能瓶颈。当系统中只有 I/O 类型的进程在运行时,iowait 也会很高,但实际上,磁盘的读写远没有达到性能瓶颈的程度。

因此,碰到 iowait 升高时,

需要先用 dstat、pidstat 等工具,确认是不是磁盘 I/O 的问题,

然后再找是哪些进程导致了 I/O。等待 I/O 的进程一般是不可中断状态,

用 ps 命令找到的 D 状态(即不可中断状态)的进程,多为可疑进程。

当不能用strace 直接分析 进程的系统调用时,可以通过perf 工具分析cpu时钟事件,找到对应的调用消耗,在源码中对应的系统调用部分,即可定位到实际的问题。

Logo

一站式 AI 云服务平台

更多推荐