环境准备
预先安装 docker、sysstat 等工具,如 apt install docker.io sysstat
操作和分析
在终端中执行下面的命令
docker run -v /tmp:/tmp --name=app -itd feisky/logapp
然后,在终端中运行 ps 命令,确认案例应用正常启动。如果操作无误,你应该可以在 ps 的输出中,看到一个 app.py 的进程:
ps -ef | grep /app.py
运行 top 命令
系统 CPU 使用率(sys%)为 22%,而 iowait 超过了 60%。这说明 CPU 上,可能正在运行 I/O 密集型的进程。
python 进程的 CPU 使用率已经达到了 37%,其余进程CPU使用率都不高
运行 iostat 命令
iostat -x -d 1
磁盘 sda 的 I/O 使用率已经高达 99%,很可能已经接近 I/O 饱和。
每秒写磁盘请求数是 1539,写大小是 98MB,写请求的响应时间为 0.1秒,而请求队列长度则达到了 117。
超慢的响应时间和特长的请求队列长度,进一步验证了 I/O 已经饱和的猜想。此时,vda 磁盘已经遇到了严重的性能瓶颈。
pidstat -d 1
python 进程到底在写什么
在终端中运行 strace 命令,并通过 -p 14919指定 python 进程的 PID 号:
strace -p 14919
write() 系统调用上,我们可以看到,进程向文件描述符编号为 3 的文件中,写入了 300MB 的数据。看来,它应该是我们要找的文件。不过,write() 调用中只能看到文件的描述符编号,文件名和路径还是未知的。
再观察后面的 stat() 调用,你可以看到,它正在获取 /tmp/logtest.txt.1 的状态。 这种“点 + 数字格式”的文件,在日志回滚中非常常见。我们可以猜测,这是第一个日志回滚文件,而正在写的日志文件路径,则是 /tmp/logtest.txt。
lsof用来查看进程打开文件列表,不过,这里的“文件”不只有普通文件,还包括了目录、块设备、动态库、网络套接字等。
lsof -p 14919
这个进程打开了文件 /tmp/logtest.txt,并且它的文件描述符是 3 号,而 3 后面的 w ,表示以写的方式打开。