首页

linux系统中一次用户态进程死循环案例的分析过程以及解决办法

1、问题现象

业务进程(用户态多线程程序)挂死,操作系统反应迟钝,系统日志没有任何异常。从进程的内核态堆栈看,看似所有线程都卡在了内核态的如下堆栈流程中:

[root@vmc116 ~]# cat /proc/27007/task/11825/stack

[<ffffffff8100baf6>] retint_careful+0x14/0x32

[<ffffffffffffffff>] 0xffffffffffffffff

2、问题分析

1)内核堆栈分析

从内核堆栈看,所有进程都阻塞在 retint_careful上,这个是中断返回过程中的流程,代码(汇编)如下:

entry_64.S

复制代码

代码如下:

ret_from_intr:
DISABLE_INTERRUPTS(CLBR_NONE)
TRACE_IRQS_OFF
decl PER_CPU_VAR(irq_count)
/* Restore saved previous stack */
popq %rsi
CFI_DEF_CFA rsi,SS+8-RBP /* reg/off reset after def_cfa_expr */
leaq ARGOFFSET-RBP(%rsi), %rsp
CFI_DEF_CFA_REGISTER rsp
CFI_ADJUST_CFA_OFFSET RBP-ARGOFFSET
。。。
retint_careful:
CFI_RESTORE_STATE
bt $TIF_NEED_RESCHED,%edx
jnc retint_signal
TRACE_IRQS_ON
ENABLE_INTERRUPTS(CLBR_NONE)
pushq_cfi %rdi
SCHEDULE_USER
popq_cfi %rdi
GET_THREAD_INFO(%rcx)
DISABLE_INTERRUPTS(CLBR_NONE)
TRACE_IRQS_OFF
jmp retint_check

这其实是用户态进程在用户态被中断打断后,从中断返回的流程,结合retint_careful+0x14/0x32,进行反汇编,可以确认阻塞的点其实就在
SCHEDULE_USER
这其实就是调用schedule()进行调度,也就是说当进程走到中断返回的流程中时,发现需要调度(设置了TIF_NEED_RESCHED),于是在这里发生了调度。
有一个疑问:为什么在堆栈中看不到schedule()这一级的栈帧呢?
因为这里是汇编直接调用的,没有进行相关栈帧压栈和上下文保存操作。

2)进行状态信息分析
从top命令结果看,相关线程实际一直处于R状态,CPU几乎完全耗尽,而且绝大部分都消耗在用户态:
[root@vmc116 ~]# top
top - 09:42:23 up 16 days, 2:21, 23 users, load average: 84.08, 84.30, 83.62
Tasks: 1037 total, 85 running, 952 sleeping, 0 stopped, 0 zombie
Cpu(s): 97.6%us, 2.2%sy, 0.2%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 32878852k total, 32315464k used, 563388k free, 374152k buffers
Swap: 35110904k total, 38644k used, 35072260k free, 28852536k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
27074 root 20 0 5316m 163m 14m R 10.2 0.5 321:06.17 z_itask_templat
27084 root 20 0 5316m 163m 14m R 10.2 0.5 296:23.37 z_itask_templat
27085 root 20 0 5316m 163m 14m R 10.2 0.5 337:57.26 z_itask_templat
27095 root 20 0 5316m 163m 14m R 10.2 0.5 327:31.93 z_itask_templat
27102 root 20 0 5316m 163m 14m R 10.2 0.5 306:49.44 z_itask_templat
27113 root 20 0 5316m 163m 14m R 10.2 0.5 310:47.41 z_itask_templat
25730 root 20 0 5316m 163m 14m R 10.2 0.5 283:03.37 z_itask_templat
30069 root 20 0 5316m 163m 14m R 10.2 0.5 283:49.67 z_itask_templat
13938 root 20 0 5316m 163m 14m R 10.2 0.5 261:24.46 z_itask_templat
16326 root 20 0 5316m 163m 14m R 10.2 0.5 150:24.53 z_itask_templat
6795 root 20 0 5316m 163m 14m R 10.2 0.5 100:26.77 z_itask_templat
27063 root 20 0 5316m 163m 14m R 9.9 0.5 337:18.77 z_itask_templat
27065 root 20 0 5316m 163m 14m R 9.9 0.5 314:24.17 z_itask_templat
27068 root 20 0 5316m 163m 14m R 9.9 0.5 336:32.78 z_itask_templat
27069 root 20 0 5316m 163m 14m R 9.9 0.5 338:55.08 z_itask_templat
27072 root 20 0 5316m 163m 14m R 9.9 0.5 306:46.08 z_itask_templat
27075 root 20 0 5316m 163m 14m R 9.9 0.5 316:49.51 z_itask_templat
...

3)进程调度信息
从相关线程的调度信息看:
[root@vmc116 ~]# cat /proc/27007/task/11825/schedstat
15681811525768 129628804592612 3557465
[root@vmc116 ~]# cat /proc/27007/task/11825/schedstat
15682016493013 129630684625241 3557509
[root@vmc116 ~]# cat /proc/27007/task/11825/schedstat
15682843570331 129638127548315 3557686
[root@vmc116 ~]# cat /proc/27007/task/11825/schedstat
15683323640217 129642447477861 3557793
[root@vmc116 ~]# cat /proc/27007/task/11825/schedstat
15683698477621 129645817640726 3557875
发现相关线程的调度统计一直在增加,说明相关线程一直是在被调度运行的,结合其状态也一直是R,推测很可能在用户态发生了死循环(或者非睡眠死锁)。

这里又有问题:为什么从top看每个线程的CPU占用率只有10%左右,而不是通常看到的死循环进程导致的100%的占用率?
因为线程数很多,而且优先级都一样,根据CFS调度算法,会平均分配时间片,不会让其中一个线程独占CPU。结果为多个线程间轮流调度,消耗掉了所有的cpu。。
另一个问题:为什么这种情况下,内核没有检测到softlockup?
因为业务进程的优先级不高,不会影响watchdog内核线程(最高优先级的实时线程)的调度,所以不会产生softlockup的情况。
再一个问题:为什么每次查看线程堆栈时,总是阻塞在retint_careful,而不是其它地方?
因为这里(中断返回的时候)正是调度的时机点,在其它时间点不能发生调度(不考虑其它情况~),而我们查看线程堆栈的行为,也必须依赖于进程调度,所以我们每次查看堆栈时,正是查看堆栈的进程(cat命令)得到调度的时候,这时正是中断返回的时候,所以正好看到的阻塞点为retint_careful。

4)用户态分析
从上面的分析看,推测应该是用户态发生了死锁。

用户态确认方法:
部署debug信息,然后gdb attach相关进程,确认堆栈,并结合代码逻辑分析。
最终确认该问题确为用户态进程中产生了死循环。

以上就是linux系统中一次用户态进程死循环案例的分析过程,谢谢阅读,希望能帮到大家,请继续关注脚本之家,我们会努力分享更多优秀的文章。