使用 RCU 的 CPU 停頓檢測器

本文件首先討論 RCU 的 CPU 停頓檢測器可以定位哪些型別的問題,然後討論可用於微調檢測器操作的核心引數和 Kconfig 選項。最後,本文件解釋停頓檢測器的“splat”格式。

什麼原因導致 RCU CPU 停頓警告?

您的核心輸出了 RCU CPU 停頓警告。下一個問題是“是什麼原因造成的?” 以下問題可能導致 RCU CPU 停頓警告

  • CPU 在 RCU 讀取側臨界區中迴圈。

  • CPU 在停用中斷的情況下迴圈。

  • CPU 在停用搶佔的情況下迴圈。

  • CPU 在停用底部半部的情況下迴圈。

  • 對於 !CONFIG_PREEMPTION 核心,CPU 在核心中的任何位置迴圈,而沒有可能呼叫 schedule()。如果核心中的迴圈確實是預期和理想的行為,您可能需要新增一些對 cond_resched() 的呼叫。

  • 使用控制檯連線啟動 Linux,該連線速度太慢,無法跟上啟動時的控制檯訊息速率。例如,115Kbaud 的序列控制檯速度可能慢,無法跟上啟動時的訊息速率,並且經常會導致 RCU CPU 停頓警告訊息。特別是如果您添加了除錯printk()

  • 任何阻止 RCU 的寬限期 kthread 執行的東西。這可能會導致“All QSes seen”控制檯日誌訊息。此訊息將包含有關 kthread 上次執行時間和預期執行頻率的資訊。它也可能導致rcu_.*kthread starved for控制檯日誌訊息,其中將包含其他除錯資訊。

  • CONFIG_PREEMPTION 核心中 CPU 繫結的即時任務,它可能恰好在 RCU 讀取側臨界區中間搶佔低優先順序任務。如果該低優先順序任務不被允許在任何其他 CPU 上執行,這將尤其具有破壞性,在這種情況下,下一個 RCU 寬限期可能永遠無法完成,這將最終導致系統耗盡記憶體並掛起。當系統正在耗盡記憶體時,您可能會看到停頓警告訊息。

  • CONFIG_PREEMPT_RT 核心中 CPU 繫結的即時任務,它以高於 RCU softirq 執行緒的優先順序執行。這將阻止 RCU 回撥被呼叫,並且在 CONFIG_PREEMPT_RCU 核心中將進一步阻止 RCU 寬限期完成。無論哪種方式,系統最終都會耗盡記憶體並掛起。在 CONFIG_PREEMPT_RCU 情況下,您可能會看到停頓警告訊息。

    您可以使用 rcutree.kthread_prio 核心引導引數來提高 RCU kthread 的排程優先順序,這可以幫助避免此問題。但是,請注意,這樣做可能會增加系統的上下文切換率,從而降低效能。

  • 週期性中斷,其處理程式花費的時間超過連續中斷對之間的時間間隔。這可能會阻止 RCU 的 kthread 和 softirq 處理程式執行。請注意,某些高開銷除錯選項,例如 function_graph 跟蹤器,可能會導致中斷處理程式花費的時間比正常情況長得多,這反過來可能會導致 RCU CPU 停頓警告。

  • 在快速系統上測試工作負載,將停頓警告超時調低到剛好避免 RCU CPU 停頓警告,然後在慢速系統上以相同的停頓警告超時執行相同的工作負載。請注意,熱節流和按需調速器可能會導致單個系統有時快速,有時緩慢!

  • 硬體或軟體問題關閉了不在 dyntick-idle 模式下的 CPU 上的排程程式時鐘中斷。這個問題確實發生過,並且似乎最有可能導致 CONFIG_NO_HZ_COMMON=n 核心的 RCU CPU 停頓警告。

  • 硬體或軟體問題,阻止基於時間的喚醒發生。這些問題可能包括配置錯誤或有缺陷的定時器硬體、中斷或異常路徑中的錯誤(無論是硬體、韌體還是軟體)、Linux 定時器子系統中的錯誤、排程程式中的錯誤,甚至包括 RCU 本身的錯誤。它也可能導致rcu_.*timer wakeup didn't happen for控制檯日誌訊息,其中將包含其他除錯資訊。

  • 定時器問題導致時間看起來向前跳躍,因此 RCU 認為 RCU CPU 停頓警告超時已超過,而實際上經過的時間要少得多。這可能是由於定時器硬體錯誤、定時器驅動程式錯誤,甚至可能是“jiffies”全域性變數的損壞。在測試新硬體時,這些型別的定時器硬體和驅動程式錯誤並不少見。

  • 底層核心問題,要麼未能呼叫 rcu_eqs_enter(true)、rcu_eqs_exit(true)、ct_idle_enter()、ct_idle_exit()、ct_irq_enter() 或 ct_irq_exit() 的變體之一,要麼在另一方面,呼叫其中之一的次數過多。從歷史上看,最常見的問題是遺漏了 irq_enter() 或 irq_exit(),這反過來分別呼叫 ct_irq_enter() 或 ct_irq_exit()。使用 CONFIG_RCU_EQS_DEBUG=y 構建核心可以幫助追蹤這些型別的問題,這些問題有時會出現在特定於架構的程式碼中。

  • RCU 實現中的錯誤。

  • 硬體故障。這是非常不可能的,但在大型資料中心中根本不常見。在幾十年前一個令人難忘的案例中,CPU 在執行的系統中出現故障,變得無響應,但沒有導致立即崩潰。這導致了一系列 RCU CPU 停頓警告,最終導致人們意識到 CPU 已經發生故障。

RCU、RCU-sched、RCU-tasks 和 RCU-tasks-trace 實現具有 CPU 停頓警告。請注意,SRCU *沒有* CPU 停頓警告。請注意,RCU 僅在寬限期進行時檢測到 CPU 停頓。沒有寬限期,就沒有 CPU 停頓警告。

要診斷停頓的原因,請檢查堆疊跟蹤。有問題的函式通常位於堆疊頂部附近。如果您有一系列來自單個擴充套件停頓的停頓警告,比較堆疊跟蹤通常可以幫助確定停頓發生的位置,這通常是在堆疊的頂部附近的函式中,該部分從一個跟蹤到另一個跟蹤保持不變。如果您可以可靠地觸發停頓,ftrace 會非常有用。

RCU 錯誤通常可以在 CONFIG_RCU_TRACE 和 RCU 的事件跟蹤的幫助下進行除錯。有關 RCU 事件跟蹤的資訊,請參閱 include/trace/events/rcu.h。

微調 RCU CPU 停頓檢測器

rcuupdate.rcu_cpu_stall_suppress 模組引數停用 RCU 的 CPU 停頓檢測器,該檢測器檢測不適當地延遲 RCU 寬限期的條件。此模組引數預設啟用 CPU 停頓檢測,但可以透過啟動時引數或在執行時透過 sysfs 覆蓋。停頓檢測器對構成“不適當延遲”的理解由一組核心配置變數和 cpp 宏控制

CONFIG_RCU_CPU_STALL_TIMEOUT

此核心配置引數定義 RCU 從寬限期開始到發出 RCU CPU 停頓警告的時間段。此時間段通常為 21 秒。

此配置引數可以在執行時透過 /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout 更改,但是此引數僅在週期開始時檢查。因此,如果您在 40 秒的停頓中已經過了 10 秒,將此 sysfs 引數設定為(例如)5 將縮短*下一個*停頓的超時時間,或者當前停頓的以下警告(假設停頓持續足夠長)。它不會影響當前停頓的下一個警告的計時。

可以透過 /sys/module/rcupdate/parameters/rcu_cpu_stall_suppress 完全啟用和停用停頓警告訊息。

CONFIG_RCU_EXP_CPU_STALL_TIMEOUT

與 CONFIG_RCU_CPU_STALL_TIMEOUT 引數相同,但僅適用於加速寬限期。此引數定義 RCU 從加速寬限期開始到發出 RCU CPU 停頓警告的時間段。此時間段在 Android 裝置上通常為 20 毫秒。值為零會導致使用 CONFIG_RCU_CPU_STALL_TIMEOUT 值,在轉換為毫秒後。

此配置引數可以在執行時透過 /sys/module/rcupdate/parameters/rcu_exp_cpu_stall_timeout 更改,但是此引數僅在週期開始時檢查。如果您處於當前停頓週期中,將其設定為新值將更改-下一個-停頓的超時時間。

可以透過 /sys/module/rcupdate/parameters/rcu_cpu_stall_suppress 完全啟用和停用停頓警告訊息。

RCU_STALL_DELAY_DELTA

雖然 lockdep 工具非常有用,但它確實增加了一些開銷。因此,在 CONFIG_PROVE_RCU 下,RCU_STALL_DELAY_DELTA 宏允許在給出 RCU CPU 停頓警告訊息之前額外等待 5 秒。(這是一個 cpp 宏,而不是核心配置引數。)

RCU_STALL_RAT_DELAY

CPU 停頓檢測器嘗試使有問題的 CPU 列印自己的警告,因為這通常會提供更高質量的堆疊跟蹤。但是,如果有問題的 CPU 未能在 RCU_STALL_RAT_DELAY 指定的節拍數中檢測到自己的停頓,則其他 CPU 將會抱怨。此延遲通常設定為兩個節拍。(這是一個 cpp 宏,而不是核心配置引數。)

rcuupdate.rcu_task_stall_timeout

此引導/sysfs 引數控制 RCU-tasks 和 RCU-tasks-trace 停頓警告間隔。值為零或更小會抑制 RCU-tasks 停頓警告。正值以秒為單位設定停頓警告間隔。RCU-tasks 停頓警告以行開始

INFO: rcu_tasks detected stalls on tasks

並繼續輸出 sched_show_task() 以獲取每個停頓當前 RCU-tasks 寬限期的任務。

RCU-tasks-trace 停頓警告以類似的方式開始(並繼續)

INFO: rcu_tasks_trace detected stalls on tasks

解釋 RCU 的 CPU 停頓檢測器“Splats”

對於 RCU 的非 RCU-tasks 風格,當 CPU 檢測到某些其他 CPU 正在停頓時,它將列印類似於以下內容的訊息

INFO: rcu_sched detected stalls on CPUs/tasks:
2-...: (3 GPs behind) idle=06c/0/0 softirq=1453/1455 fqs=0
16-...: (0 ticks this GP) idle=81c/0/0 softirq=764/764 fqs=0
(detected by 32, t=2603 jiffies, g=7075, q=625)

此訊息指示 CPU 32 檢測到 CPU 2 和 CPU 16 都在導致停頓,並且該停頓正在影響 RCU-sched。此訊息通常後跟每個 CPU 的堆疊轉儲。請注意,PREEMPT_RCU 構建可能會因任務以及 CPU 而停頓,並且任務將由 PID 指示,例如,“P3421”。甚至可能出現 rcu_state 停頓是由 CPU *和* 任務引起的,在這種情況下,有問題的 CPU 和任務都將在列表中被呼叫。在某些情況下,CPU 將檢測到自身停頓,這將導致自身檢測到的停頓。

CPU 2 的“(3 GPs behind)”指示此 CPU 在過去的三個寬限期內沒有與 RCU 核心互動。相反,CPU 16 的“(0 ticks this GP)”指示此 CPU 在當前停頓的寬限期內沒有采取任何排程程式時鐘中斷。

訊息的“idle=”部分列印 dyntick-idle 狀態。第一個“/”之前的十六進位制數字是 dynticks 計數器的低 16 位,如果 CPU 處於 dyntick-idle 模式,則該值將為偶數,否則將為奇數。兩個“/”之間的十六進位制數字是巢狀的值,如果在空閒迴圈中(如上所示)則該值將是一個小的非負數,否則將是一個非常大的正數。最後一個“/”之後的數字是 NMI 巢狀,它將是一個小的非負數。

訊息的“softirq=”部分跟蹤停頓的 CPU 已執行的 RCU softirq 處理程式的數量。 “/”之前的數字是在引導後執行的次數,在該 CPU 上次注意到寬限期開始時,這可能是當前的(停頓的)寬限期,或者可能是較早的寬限期(例如,如果 CPU 可能在 dyntick-idle 模式下停留了很長時間)。 “/”之後的數字是自引導以來直到當前時間執行的次數。如果後一個數字在重複的停頓警告訊息中保持不變,則 RCU 的 softirq 處理程式可能無法在此 CPU 上執行。如果停頓的 CPU 在停用中斷的情況下旋轉,或者在 -rt 核心中,如果高優先順序程序正在使 RCU 的 softirq 處理程式飢餓,則可能會發生這種情況。

“fqs=”顯示自上次此 CPU 注意到寬限期開始以來,寬限期 kthread 在此 CPU 上進行的強制靜止狀態空閒/離線檢測傳遞的次數。

“detected by”行指示哪個 CPU 檢測到停頓(在這種情況下,CPU 32),自寬限期開始以來經過了多少節拍(在這種情況下為 2603),寬限期序列號(7075),以及所有 CPU 上排隊的 RCU 回撥總數的估計值(在這種情況下為 625)。

如果寬限期恰好在停頓警告開始列印時結束,則會有一個虛假的停頓警告訊息,其中將包括以下內容

INFO: Stall ended before state dump start

這種情況很少見,但在現實生活中確實會不時發生。在這種情況下,還可能標記零節拍停頓,具體取決於停頓警告和寬限期初始化的互動方式。請注意,如果不訴諸 stop_machine() 之類的東西,則不可能完全消除這種誤報,對於這種問題來說,stop_machine() 是一種過度行為。

如果所有 CPU 和任務都已透過靜止狀態,但寬限期仍然未能結束,則停頓警告 splat 將包括以下內容

All QSes seen, last rcu_preempt kthread activity 23807 (4297905177-4297881370), jiffies_till_next_fqs=3, root ->qsmask 0x0

“23807”表示自寬限期 kthread 執行以來已經超過 23,000 個節拍。 “jiffies_till_next_fqs”指示該 kthread 應該執行的頻率,給出強制靜止狀態掃描之間的節拍數,在這種情況下為 3,遠小於 23807。最後,列印根 rcu_node 結構的 ->qsmask 欄位,該欄位通常為零。

如果在停頓警告之前相關的寬限期 kthread 無法執行,如上面的“All QSes seen”行所示,則會列印以下附加行

rcu_sched kthread starved for 23807 jiffies! g7075 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1 ->cpu=5
Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.

使寬限期 kthread 缺乏 CPU 時間當然會導致 RCU CPU 停頓警告,即使所有 CPU 和任務都已透過所需的靜止狀態。 “g”數字顯示當前寬限期序列號,“f”位於 ->gp_flags 命令之前傳送到寬限期 kthread,“RCU_GP_WAIT_FQS”表示 kthread 正在等待短超時,“state”位於 task_struct ->state 欄位的值之前,“cpu”表示寬限期 kthread 上次在 CPU 5 上執行。

如果相關的寬限期 kthread 未能在合理的時間內從 FQS 等待中喚醒,則會列印以下附加行

kthread timer wakeup didn't happen for 23804 jiffies! g7076 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402

“23804”表示 kthread 的定時器在 23,000 多個節拍之前已過期。該行的其餘部分具有類似於 kthread 飢餓情況的含義。

此外,還會列印以下行

Possible timer handling issue on cpu=4 timer-softirq=11142

這裡的“cpu”表示寬限期 kthread 上次在 CPU 4 上執行,它在其中排隊了 fqs 定時器。 “timer-softirq”之後的數字是 cpu 4 上的當前 TIMER_SOFTIRQ 計數。如果此值在連續的 RCU CPU 停頓警告中沒有變化,則更有理由懷疑是定時器問題。

這些訊息通常後跟涉及停頓的 CPU 和任務的堆疊轉儲。這些堆疊跟蹤可以幫助您找到停頓的原因,請記住,檢測停頓的 CPU 將具有一個主要用於檢測停頓的中斷幀。

來自一個停頓的多個警告

如果停頓持續足夠長的時間,將為該停頓列印多個停頓警告訊息。第二個和後續訊息以更長的時間間隔列印,因此第一個和第二個訊息之間的時間間隔大約是停頓開始和第一個訊息之間的時間間隔的三倍。比較同一停頓寬限期的不同訊息的堆疊轉儲可能會有所幫助。

加速寬限期的停頓警告

如果加速寬限期檢測到停頓,它將在 dmesg 中放置類似以下內容的訊息

INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 7-... } 21119 jiffies s: 73 root: 0x2/.

這表示 CPU 7 未能響應重新排程 IPI。 CPU 編號後的三個句點(“.”)表示 CPU 線上(否則,第一個句點將改為“O”),CPU 在加速寬限期開始時線上(否則,第二個句點將改為“o”),並且 CPU 自引導後至少線上一次(否則,第三個句點將改為“N”)。 “jiffies”之前的數字表示加速寬限期已經進行了 21,119 個節拍。 “s:”之後的數字表示加速寬限期序列計數器為 73。事實上,最後一個值為奇數表示加速寬限期正在進行中。“root:”之後的數字是一個位掩碼,表示根 rcu_node 結構的哪些子項對應於阻止當前加速寬限期的 CPU 和/或任務。如果樹有多個級別,則將為樹中其他 rcu_node 結構的狀態列印附加十六進位制數字。

與正常寬限期一樣,PREEMPT_RCU 構建可能會因任務以及 CPU 而停頓,並且任務將由 PID 指示,例如,“P3421”。

完全有可能在同一次執行期間幾乎同時看到來自正常寬限期和加速寬限期的停頓警告。

RCU_CPU_STALL_CPUTIME

在以 CONFIG_RCU_CPU_STALL_CPUTIME=y 構建或以 rcupdate.rcu_cpu_stall_cputime=1 引導的核心中,每個 RCU CPU 停頓警告都會提供以下附加資訊

rcu:          hardirqs   softirqs   csw/system
rcu:  number:      624         45            0
rcu: cputime:       69          1         2425   ==> 2500(ms)

這些統計資訊是在取樣期間收集的。 “number:”行中的值是有問題的 CPU 上的硬中斷數、軟中斷數和上下文切換數。 “cputime:”行中的前三個值表示有問題的 CPU 上的硬中斷、軟中斷和任務消耗的 CPU 時間(以毫秒為單位)。最後一個數字是測量間隔,也以毫秒為單位。因為使用者模式任務通常不會導致 RCU CPU 停頓,所以這些任務通常是核心任務,這就是為什麼只考慮系統 CPU 時間。

取樣週期顯示如下

|<------------first timeout---------->|<-----second timeout----->|
|<--half timeout-->|<--half timeout-->|                          |
|                  |<--first period-->|                          |
|                  |<-----------second sampling period---------->|
|                  |                  |                          |
           snapshot time point    1st-stall                  2nd-stall

以下描述了四種典型情況

  1. CPU 在停用中斷的情況下迴圈。

    rcu:          hardirqs   softirqs   csw/system
    rcu:  number:        0          0            0
    rcu: cputime:        0          0            0   ==> 2500(ms)
    

    因為在整個測量間隔內停用了中斷,所以沒有中斷,也沒有上下文切換。此外,因為 CPU 時間消耗是使用中斷處理程式測量的,所以系統 CPU 消耗被錯誤地測量為零。這種情況通常還會在該 CPU 的摘要行上列印“(0 ticks this GP)”。

  2. CPU 在停用底部半部的情況下迴圈。

    這與前面的示例類似,但硬中斷的非零數量和 CPU 時間消耗,以及核心執行消耗的非零 CPU 時間

    rcu:          hardirqs   softirqs   csw/system
    rcu:  number:      624          0            0
    rcu: cputime:       49          0         2446   ==> 2500(ms)
    

    沒有軟中斷這一事實暗示這些已停用,可能是透過 local_bh_disable()。當然,有可能沒有軟中斷,可能是因為所有會導致軟中斷執行的事件都僅限於其他 CPU。在這種情況下,應繼續診斷,如下一個示例所示。

  3. CPU 在停用搶佔的情況下迴圈。

    在這裡,只有上下文切換數為零

    rcu:          hardirqs   softirqs   csw/system
    rcu:  number:      624         45            0
    rcu: cputime:       69          1         2425   ==> 2500(ms)
    

    這種情況暗示停頓的 CPU 在停用搶佔的情況下迴圈。

  4. 沒有迴圈,但大量的硬中斷和軟中斷。

    rcu:          hardirqs   softirqs   csw/system
    rcu:  number:       xx         xx            0
    rcu: cputime:       xx         xx            0   ==> 2500(ms)
    

    在這裡,硬中斷的數量和 CPU 時間都是非零的,但上下文切換數和消耗的核心 CPU 時間為零。軟中斷的數量和 cputime 通常為非零,但可能為零,例如,如果 CPU 在單個硬中斷處理程式中旋轉。

    如果可以重現這種型別的 RCU CPU 停頓警告,您可以透過檢視 /proc/interrupts 或編寫程式碼來跟蹤每個中斷(例如,透過參考 show_interrupts())來縮小範圍。