Chinaunix首页 | 论坛 | 博客
  • 博客访问: 1247495
  • 博文数量: 122
  • 博客积分: 0
  • 博客等级: 民兵
  • 技术积分: 4004
  • 用 户 组: 普通用户
  • 注册时间: 2014-02-20 08:27
文章分类
文章存档

2016年(1)

2015年(21)

2014年(100)

分类: LINUX

2014-09-17 18:29:20

1、问题现象
业务进程(用户态多线程程序)挂死,操作系统反应迟钝,系统日志没有任何异常。从进程的内核态堆栈看,看似所有线程都卡在了内核态的如下堆栈流程中:
[root@vmc116 ~]# cat /proc/27007/task/11825/stack
[] retint_careful+0x14/0x32
[] 0xffffffffffffffff

2、问题分
1)内核堆栈分析
从内核堆栈看,所有进程都阻塞在 retint_careful上,这个是中断返回过程中的流程,代码(汇编)如下:
entry_64.S

点击(此处)折叠或打开

  1. ret_from_intr:
  2.     DISABLE_INTERRUPTS(CLBR_NONE)
  3.     TRACE_IRQS_OFF
  4.     decl PER_CPU_VAR(irq_count)

  5.     /* Restore saved previous stack */
  6.     popq %rsi
  7.     CFI_DEF_CFA rsi,SS+8-RBP    /* reg/off reset after def_cfa_expr */
  8.     leaq ARGOFFSET-RBP(%rsi), %rsp
  9.     CFI_DEF_CFA_REGISTER    rsp
  10.     CFI_ADJUST_CFA_OFFSET    RBP-ARGOFFSET
  11. 。。。
  12. 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相关进程,确认堆栈,并结合代码逻辑分析。
最终确认该问题确为用户态进程中产生了死循环。

阅读(4679) | 评论(0) | 转发(3) |
给主人留下些什么吧!~~