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

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

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

1、問題現(xiàn)象

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

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

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

[<ffffffffffffffff>] 0xffffffffffffffff

2、問題分析

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

從內(nèi)核堆?？矗羞M程都阻塞在 retint_careful上，這個是中斷返回過程中的流程，代碼(匯編)如下：

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

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

2）進行狀態(tài)信息分析
從top命令結(jié)果看，相關(guān)線程實際一直處于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）進程調(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)計一直在增加，說明相關(guān)線程一直是在被調(diào)度運行的，結(jié)合其狀態(tài)也一直是R，推測很可能在用戶態(tài)發(fā)生了死循環(huán)(或者非睡眠死鎖)。

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

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

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

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