linux系統(tǒng)中一次用戶態(tài)進(jìn)程死循環(huán)案例的分析過(guò)程以及解決辦法

發(fā)布時(shí)間：2014-10-09 09:32:00 作者：佚名

這篇文章主要為大家介紹了linux系統(tǒng)中用戶態(tài)進(jìn)程死循環(huán)的分析過(guò)程，業(yè)務(wù)進(jìn)程(用戶態(tài)多線程程序)掛死，操作系統(tǒng)反應(yīng)遲鈍，系統(tǒng)日志沒(méi)有任何異常。從進(jìn)程的內(nèi)核態(tài)堆棧看，看似所有線程都卡在了內(nèi)核態(tài)的堆棧流程，其實(shí)不是，那么如何分析造成死循環(huán)的原因？請(qǐng)看下文

1、問(wèn)題現(xiàn)象

業(yè)務(wù)進(jìn)程(用戶態(tài)多線程程序)掛死，操作系統(tǒng)反應(yīng)遲鈍，系統(tǒng)日志沒(méi)有任何異常。從進(jìn)程的內(nèi)核態(tài)堆?？?，看似所有線程都卡在了內(nèi)核態(tài)的如下堆棧流程中：

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

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

[<ffffffffffffffff>] 0xffffffffffffffff

2、問(wèn)題分析

1）內(nèi)核堆棧分析

從內(nèi)核堆棧看，所有進(jìn)程都阻塞在 retint_careful上，這個(gè)是中斷返回過(guò)程中的流程，代碼(匯編)如下：

entry_64.S

復(fù)制代碼

代碼如下:

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

這其實(shí)是用戶態(tài)進(jìn)程在用戶態(tài)被中斷打斷后，從中斷返回的流程，結(jié)合retint_careful+0x14/0x32，進(jìn)行反匯編，可以確認(rèn)阻塞的點(diǎn)其實(shí)就在
SCHEDULE_USER
這其實(shí)就是調(diào)用schedule()進(jìn)行調(diào)度，也就是說(shuō)當(dāng)進(jìn)程走到中斷返回的流程中時(shí)，發(fā)現(xiàn)需要調(diào)度(設(shè)置了TIF_NEED_RESCHED)，于是在這里發(fā)生了調(diào)度。
有一個(gè)疑問(wèn)：為什么在堆棧中看不到schedule()這一級(jí)的棧幀呢？
因?yàn)檫@里是匯編直接調(diào)用的，沒(méi)有進(jìn)行相關(guān)棧幀壓棧和上下文保存操作。

2）進(jìn)行狀態(tài)信息分析
從top命令結(jié)果看，相關(guān)線程實(shí)際一直處于R狀態(tài)，CPU幾乎完全耗盡，而且絕大部分都消耗在用戶態(tài)：
[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）進(jìn)程調(diào)度信息
從相關(guān)線程的調(diào)度信息看：
[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
發(fā)現(xiàn)相關(guān)線程的調(diào)度統(tǒng)計(jì)一直在增加，說(shuō)明相關(guān)線程一直是在被調(diào)度運(yùn)行的，結(jié)合其狀態(tài)也一直是R，推測(cè)很可能在用戶態(tài)發(fā)生了死循環(huán)(或者非睡眠死鎖)。

這里又有問(wèn)題：為什么從top看每個(gè)線程的CPU占用率只有10%左右，而不是通常看到的死循環(huán)進(jìn)程導(dǎo)致的100%的占用率？
因?yàn)榫€程數(shù)很多，而且優(yōu)先級(jí)都一樣，根據(jù)CFS調(diào)度算法，會(huì)平均分配時(shí)間片，不會(huì)讓其中一個(gè)線程獨(dú)占CPU。結(jié)果為多個(gè)線程間輪流調(diào)度，消耗掉了所有的cpu。。
另一個(gè)問(wèn)題：為什么這種情況下，內(nèi)核沒(méi)有檢測(cè)到softlockup？
因?yàn)闃I(yè)務(wù)進(jìn)程的優(yōu)先級(jí)不高，不會(huì)影響watchdog內(nèi)核線程(最高優(yōu)先級(jí)的實(shí)時(shí)線程)的調(diào)度，所以不會(huì)產(chǎn)生softlockup的情況。
再一個(gè)問(wèn)題：為什么每次查看線程堆棧時(shí)，總是阻塞在retint_careful，而不是其它地方？
因?yàn)檫@里(中斷返回的時(shí)候)正是調(diào)度的時(shí)機(jī)點(diǎn)，在其它時(shí)間點(diǎn)不能發(fā)生調(diào)度(不考慮其它情況~)，而我們查看線程堆棧的行為，也必須依賴于進(jìn)程調(diào)度，所以我們每次查看堆棧時(shí)，正是查看堆棧的進(jìn)程(cat命令)得到調(diào)度的時(shí)候，這時(shí)正是中斷返回的時(shí)候，所以正好看到的阻塞點(diǎn)為retint_careful。

4）用戶態(tài)分析
從上面的分析看，推測(cè)應(yīng)該是用戶態(tài)發(fā)生了死鎖。

用戶態(tài)確認(rèn)方法：
部署debug信息，然后gdb attach相關(guān)進(jìn)程，確認(rèn)堆棧，并結(jié)合代碼邏輯分析。
最終確認(rèn)該問(wèn)題確為用戶態(tài)進(jìn)程中產(chǎn)生了死循環(huán)。

以上就是linux系統(tǒng)中一次用戶態(tài)進(jìn)程死循環(huán)案例的分析過(guò)程，謝謝閱讀，希望能幫到大家，請(qǐng)繼續(xù)關(guān)注腳本之家，我們會(huì)努力分享更多優(yōu)秀的文章。