[Android稳定性] 第024篇 [方法篇] RCU Stall问题如何进行分析?

一、什么是RCU?

RCU(Read-Copy-Update,读-复制-更新)是一种 高效的内存同步机制,用于在多核、多线程环境下,解决读写并发问题。它特别适合读多写少的场景,可以显著提高系统的并发性能和效率。
RCU 的核心思想是:

  • 读操作不加锁:读操作可以在不阻塞的情况下完成,因为它不会直接修改数据。
  • 写操作创建副本:写操作在更新数据前,会创建原数据的副本,并对副本进行修改。
  • 延迟释放旧数据:在确保所有读操作完成后,旧数据才会被安全地释放。
  • 通过这种机制,RCU 实现了高效的读写操作分离,避免了传统锁机制可能引发的性能瓶颈。

二、什么是RCU stall?

当 RCU 子系统检测到以下任一问题时,会触发 RCU Stall:

  • RCU Grace Period 未结束:
    RCU 的宽限期(Grace Period)超出预期时间,可能是某个 CPU 或任务未能退出其 RCU 临界区,导致 RCU 回调无法执行。
  • RCU Callback 堆积:
    RCU 的回调函数无法按时处理,可能是由于系统负载过高或 CPU 长时间未运行相关线程。
  • 长时间调度延迟:
    某些任务或内核线程被阻塞,导致系统无法及时响应 RCU 的操作。

2.1 典型日志

当 RCU Stall 发生时,内核日志会打印类似以下的消息:

1
2
3
rcu: INFO: rcu_sched detected stalls on CPUs/tasks: { 1} (detected by 0, t=2102 jiffies, g=1234, q=0)
rcu: rcu_sched kthread starved for 2102 jiffies!
rcu: 1-...!: (0 ticks this GP) idle=c06/1/0x4000000000000000 softirq=377/377 fqs=1052

rcu_sched:表明是 rcu_sched 子系统检测到了问题(RCU 的调度子系统)。
stalls on CPUs/tasks: { 1}:说明问题发生在 CPU 1 上。
t=2102 jiffies:RCU 操作已经阻塞了 2102 个 jiffies。
g=1234:当前的 Grace Period 编号。
fqs=1052:RCU 尝试了 1052 次强制加速 Grace Period 的完成。

2.2 RCU Stall 的常见原因

  • 长时间运行的任务:
    某些内核线程或用户态进程长时间占用 CPU,导致 RCU 的调度线程无法运行。
  • RCU 临界区未退出:
    某些代码在 RCU 临界区中运行时间过长,例如:
    1
    2
    3
    rcu_read_lock();
    /* 长时间循环或阻塞代码 */
    rcu_read_unlock();
  • 调度延迟:
    某些高优先级任务或中断占用了调度器,阻碍了 RCU 线程的正常运行。
  • RCU 回调堆积:
    如果系统负载很高,RCU 回调函数可能无法及时执行,导致内存泄漏或 RCU Stall。
  • 锁和死锁:
    某些代码路径可能持有锁,阻止其他线程完成 RCU 的工作。
  • CPU 停止运行:
    某些情况下,某个 CPU 被挂起或进入低功耗状态,导致 RCU 操作无法完成。

2.3 常见分析方法

2.3.1 分析内核日志

  • 使用 dmesg 查看 RCU Stall 的详细信息。
  • 确认是哪一个子系统(如 rcu_sched 或 rcu_preempt)报告了问题。

2.3.1 触发任务栈回溯

使用 sysrq 打印所有任务的堆栈

1
echo t > /proc/sysrq-trigger

分析卡住的任务的调用栈,寻找潜在的死锁或长时间运行的函数。

2.3.2 检查长时间运行的任务:

  • 使用 top 或 ps 找出占用 CPU 资源的进程。
  • 使用 perf 分析系统的性能瓶颈:
1
perf top

2.3.3 检查锁和资源争用

如果启用了内核锁依赖检测(CONFIG_LOCKDEP),查看 dmesg 是否报告锁问题。

2.3.4 启用 RCU 跟踪

打开 RCU 跟踪功能

1
echo 1 > /sys/kernel/debug/tracing/events/rcu/enable

捕获 RCU 事件并分析其行为。

2.3.5 确认系统调度问题

检查是否有任务在运行队列中等待太久:

1
cat /proc/sched_debug

2.3.6 调整 RCU 参数

增大 RCU 超时时间:

1
echo 60 > /proc/sys/kernel/rcu_cpu_stall_timeout

2.3.7 触发panic

如果希望rcu stall时panic,执行如下命令:

1
echo 1 > /proc/sys/kernel/panic_on_rcu_stall

为了能在rcu stall时得到更多信息,建议在开发版本中打开panic_on_rcu_stall,panic时如果有fulldumpvmcore生成,对定位问题有一定帮助; 正式版本建议关闭panic_on_rcu_stall,避免影响扩大化。

三、实例

3.1 dmesg日志分析

1
2
3
[176147.423615][   T19] rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 0-... } 44034492 jiffies s: 825 root: 0x1/.
[176147.435368][ T19] rcu: blocking rcu_node structures (internal RCU debug):
[176148.011593][ C0] watchdog: BUG: soft lockup - CPU#0 stuck for 164043s! [swapper/0:0]

确认为rcu stall问题,但是抓到的机器都卡白米(kernel阶段),adb也无法使用无法抓取更多的日志进行分析。

3.2 打开rcu stall触发panic复现

1
echo 1 > /proc/sys/kernel/panic_on_rcu_stall

打开这个后,安排机器测试。

3.3 串口输出进程信息

1
echo t > /proc/sysrq-trigger

得到如下的日志