nikel-rcu死鎖問題分析
一. 問題描述
1.1 問題JIRA
XXX
1.2 現象
手機卡死
1.3 結論
XXX
我們能看到在lowswap_fn方法中先呼叫了rcu_read_lock方法,然後呼叫了get_swap_unshared方法,並且在get_swap_unshared方法裡邊又呼叫了wait_rcu_gp,由於這時候還沒有呼叫rcu_read_unlock,所以在wait_rcu_gp這裡必定會卡死.卡死之後就無法呼叫rcu_read_unlock,這時候會導致所有呼叫了wait_rcu_gp方法的執行緒都卡死.
二. 初步分析
2.1 檢視system_server trace
"InputReader" prio=10 tid=40 Native
group="main" sCount=1 dsCount=0 obj=0x13a530a0 self=0x7f99ad9c00 |
sysTid=1316 nice=-8 cgrp=default sched=0/0 handle=0x7f95f06440 |
state=D schedstat=( 377512554 46994296 385 ) utm=12 stm=26 core=1 HZ=100 |
stack=0x7f95e0a000-0x7f95e0c000 stackSize=1013KB |
held mutexes= kernel: __switch_to+0x74/0x8c kernel: wait_rcu_gp+0x44/0x54 kernel: synchronize_rcu+0x28/0x40 kernel: wakeup_source_remove+0x70/0xa4 kernel: pm_wake_unlock+0x35c/0x40c kernel: wake_unlock_store+0x10/0x2c kernel: kobj_attr_store+0x10/0x24 kernel: sysfs_kf_write+0x3c/0x48 kernel: kernfs_fop_write+0x10c/0x178 kernel: vfs_write+0x98/0x1b8 kernel: SyS_write+0x40/0xa0 kernel: el0_svc_naked+0x20/0x28 native: (backtrace::Unwind failed for thread 1316) |
從這裡我們能看到system_server的InputReader執行緒卡在了wait_rcu_gp的呼叫上.
2.2 瞭解rcu
rcu的核心理念是讀者訪問的同時,寫者可以更新訪問物件的副本,但寫者需要等待所有讀者完成訪問之後,才能刪除老物件。這個過程實現的關鍵和難點就在於如何判斷所有的讀者已經完成訪問。通常把寫者開始更新,到所有讀者完成訪問這段時間叫做寬限期(Grace Period)。核心中實現寬限期等待的函式是synchronize_rcu。想要深入瞭解的同學請參考:http://www.wowotech.net/kernel_synchronization/223.html
一般synchronize_rcu是要等待所有的讀執行緒退出,例如:
rcu_read_lock();
XXX
rcu_read_unlock();
只有所有的執行緒unlock後synchronize_rcu()這行程式碼才會往下執行,否則會一直等待.
瞭解了ruc的大概原理之後我們能知道為什麼這裡會卡在synchronize_rcu上了,就是因為有其他執行緒沒有呼叫rcu_read_unlock這個方法導致的,那麼我們需要調查哪裡呼叫了rcu_read_lock方法,卻沒有呼叫rcu_read_unlock方法.
2.3 排查當時合入的程式碼
由於這個問題並沒有有效的資訊直接能看出哪裡沒有呼叫rcu_read_unlock方法,所以從log上並沒有能直接找到有效資訊.去排查了下可疑的提交,並且在念總的幫助下發現了這個提交:
我將這個change revert後發現該問題不在復現,所以直接鎖定這這個修復.
三. 進一步分析
3.1確認問題
在確認問題是由於這個提交引入的後,我從大量的log中發現瞭如下的呼叫棧:
[ 2205.544479] (1)[178:hang_detect]kworker/u20:4 D
[ 2205.544514] (1)[178:hang_detect] ffffffc000087228 <3>[ 2205.544555] (1) [178:hang_detect] 0 254 2 0x00000000
[ 2205.544605] (1)[178:hang_detect]6Workqueue: events_unbound lowswap_fn
[ 2205.544651] (1)[178:hang_detect]Call trace:
[ 2205.544698] (1)[178:hang_detect][<ffffffc000087228>] __switch_to+0x74/0x8c
[ 2205.544745] (1)[178:hang_detect][<ffffffc000b9f0b8>] __schedule+0x388/0x794
[ 2205.544792] (1)[178:hang_detect][<ffffffc000b9f4e8>] schedule+0x24/0x74
[ 2205.544842] (1)[178:hang_detect][<ffffffc000ba1fa8>] schedule_timeout+0x1ac/0x204
[ 2205.544890] (1)[178:hang_detect][<ffffffc000ba00c0>] wait_for_common+0x9c/0x14c
[ 2205.544938] (1)[178:hang_detect][<ffffffc000ba0298>] wait_for_completion+0x10/0x1c
[ 2205.544986] (1)[178:hang_detect][<ffffffc0000feab0>] wait_rcu_gp+0x44/0x54
[ 2205.545036] (1)[178:hang_detect][<ffffffc000103c10>] synchronize_rcu+0x28/0x40
[ 2205.545083] (1)[178:hang_detect][<ffffffc0005bc7a4>] kbase_special_vm_close+0x40/0x9c
[ 2205.545135] (1)[178:hang_detect][<ffffffc00018e34c>] remove_vma+0x24/0x54
[ 2205.545178] (1)[178:hang_detect][<ffffffc00019144c>] exit_mmap+0xd4/0x114
[ 2205.545225] (1)[178:hang_detect][<ffffffc00009d920>] mmput+0x4c/0xd8
[ 2205.545273] (1)[178:hang_detect][<ffffffc0009480b8>] get_swap_unshared+0xa4/0xf8
[ 2205.545320] (1)[178:hang_detect][<ffffffc000948254>] lowswap_fn+0x148/0x2a4
[ 2205.545368] (1)[178:hang_detect][<ffffffc0000b77cc>] process_one_work+0x154/0x418
[ 2205.545415] (1)[178:hang_detect][<ffffffc0000b7d3c>] worker_thread+0x2ac/0x4ec
[ 2205.545457] (1)[178:hang_detect][<ffffffc0000bd1fc>] kthread+0xd4/0xec
對應的程式碼:
XXX
我們能看到在lowswap_fn方法中先呼叫了rcu_read_lock方法,然後呼叫了get_swap_unshared方法,並且在get_swap_unshared方法裡邊又呼叫了wait_rcu_gp,由於這時候還沒有呼叫rcu_read_unlock,所以在wait_rcu_gp這裡必定會卡死.卡死之後就無法呼叫rcu_read_unlock,這時候會導致所有呼叫了wait_rcu_gp方法的執行緒都卡死.
3.2寫測試case
寫了個測試case:
直接cat對應的裝置節點:
我們能看到只要5950執行緒直接變成了D狀態,卡在了wait_rcu_gp上
3.3解決問題
四. 總結
這個問題最核心的原因就是某個執行緒呼叫rcu_read_lock後在沒有呼叫rcu_read_unlock的情況下直接呼叫了synchronize_rcu,導致了死鎖.