一次linux下ps卡住问题分析

一次linux下ps卡住问题分析

Posted by lwk on April 12, 2020

2020年4.7号晚上10点左右,有同事反馈有台zk机器出现执行命令卡住的问题,从监控视图看对应实例的负载和总进程数监控图,发现进程总数已经到了1万多个。

我看到群里消息后,立马登录到机器上查看对应指标信息,发现可以执行top,并且基础指标也正常。

image 然后就执行了一下Ps先看下,可惜卡住了,也就是ps执行不了。

image 那从/proc下去查看把,从proc看下最远时间的几个PID信息,列出其status信息,从中分析出是哪个进程有异常。

image 发现是ps进程D住了。PS是从哪里来的呢?从cmdline和exe以及/proc下的大量PID信息推断出是定时任务发出的ps。第一反应就是看crontab,如下:

image image image image image 看下进程的系统调用情况。系统调用号是0

image 在/usr/include/asm/unistd_64.h搜下对应的系统调用是谁,发现0号对应的是read。 image

同样可以查看进程的stack信息:

image image image image 也就是ps卡在这个while循环一直没有退出去。这里是在等待rwsem,但为什么会一直获取不到rwsem呢?

(下面两个图是sar数据,可以作为参考) image image 从进程堆栈、系统调用以及内核代码分析,当时ps进程处于等待rwsem(read-write semphone)的死循环一直没有退出。 image

既然ps卡住,那就用万能的strace看下系统调用情况。

strace -ttT -f -v -s1024 -o s.log ps -ef

从strace看卡在了read(6,

fd=6对应的是/proc/717/cmdline,也就是read这个文件的时候卡住了。那我们直接cat下试试呢 image 果不其然,cat也卡住了。

/proc下的文件都是内核映射到内存中的。为什么cat cmdline会hang住呢?这个进程有问题?stat看下cmdline

image 查看对应进程的信息:

image

Pid=717对应的是Java进程roc-proxy,这个进程在2020-04-06 15:42分发生了什么呢?

很显然要去看下dmesg和/var/log/message: image 发下有不少Java进程被D住了,而且从proc下查看status也最终确认确实是D住了:

image

这样就清晰了为什么crond定时任务(ps)会hang住,并且有大量crond任务存在(上万个进程)。

这里简单画个ps hang住的分析图: image

从系统日志看应该是当时机器上的Java进程hang住导致,至于为什么Java进程hang住,从trace log看应该是和当时系统内存分配有关系,这里我就不分析了,耗时太久了^_^(感兴趣的可以从trace log追踪kernel代码分析下).

另外从Kernel邮件以及centos社区看都有反馈类似问题。当前机器的linux内核版本是3.10,存在不少BUG,建议还是升级到4以上版本。

https://lkml.org/lkml/2018/2/20/576

https://lore.kernel.org/patchwork/patch/1018850/

https://bugs.centos.org/view.php?id=15252