Linux 内核分析 rcu_sched self-detected stall on CPU

打印 上一主题 下一主题

主题 662|帖子 662|积分 1986

媒介

  1. [  115.958161] rcu: INFO: rcu_sched self-detected stall on CPU
  2. [  115.989538] rcu:     3-....: (14997 ticks this GP) idle=a2e/1/0x4000000000000002 softirq=6190/6192 fqs=7448
  3. [  115.990426]  (t=15000 jiffies g=9409 q=23634)
  4. [  115.990427] Task dump for CPU 3:
  5. [  115.990429] process-name      R  running task        0  1814   1757 0x00000002
  6. [  115.990431] Call trace:
  7. [  115.990435]  dump_backtrace+0x0/0x178
  8. [  115.990436]  show_stack+0x14/0x20
  9. [  115.990438]  sched_show_task.part.0+0xe0/0x108
  10. [  115.990440]  sched_show_task+0x3c/0x40
  11. [  115.990441]  dump_cpu_task+0x40/0x4c
  12. [  115.990443]  rcu_dump_cpu_stacks+0xa0/0xe0
  13. [  115.990444]  rcu_sched_clock_irq+0x530/0x790
  14. [  115.990446]  update_process_times+0x2c/0x88
  15. [  115.990448]  tick_sched_handle.isra.0+0x30/0x50
  16. [  115.990450]  tick_sched_timer+0x48/0x98
  17. [  115.990451]  __hrtimer_run_queues+0xec/0x1e8
  18. [  115.990452]  hrtimer_interrupt+0x110/0x2c0
  19. [  115.990456]  arch_timer_handler_virt+0x30/0x40
  20. [  115.990457]  handle_percpu_devid_irq+0x80/0x140
  21. [  115.990459]  generic_handle_irq+0x24/0x38
  22. [  115.990460]  __handle_domain_irq+0x60/0xb8
  23. [  115.990461]  gic_handle_irq+0x5c/0x148
  24. [  115.990462]  el1_irq+0xb8/0x140
  25. [  115.990464]  __memset+0xf0/0x188
  26.                                 ......
复制代码
最近内核代码时出现一个偶现的BUG,进程 process-name 不绝占用着某一个进程 ,比如CPU3,进程CPU占用率100%,进程 process-name无法制止,且其使用的内核模块也无法也没法正常卸载,处于使用中,导致提示告诫:
  1. rcu: INFO: rcu_sched self-detected stall on CPU
复制代码
RCU(Read-Copy Update)的CPU停滞检测器能够定位和识别与CPU停滞相关的问题。当CPU由于各种缘故原由无法取得进展时,比方长时间运行的使命或锁争用,就会发生停滞。
当存在CPU停滞时,RCU的性能可能会受到影响。CPU停滞指的是CPU由于各种缘故原由而无法取得进展,比方繁重的盘算、长时间运行的使命、中断争用或锁争用等。这种停滞可能导致RCU无法及时完成其使命,导致脱期期内该CPU没有发生调度,从而影响体系的响应性能和吞吐量。
为了办理这些问题,Linux内核引入了RCU的CPU停滞检测器。该检测器能够监视CPU的活动并检测停滞情况。当检测到CPU停滞时,检测器会采取一些步调,比方打印告诫消息、记载调用堆栈信息或触发调试工具等,以资助开辟人员识别和办理问题。
通常是在驱动代码中的循环部门出现了问题,导致不绝占着某个CPU。
一、RCU CPU Stall 告诫的缘故原由

RCU(Read-Copy-Update)CPU停滞告诫可能由体系中的各种问题引起。以下是可能的缘故原由:
(1)CPU在RCU读侧临界区域中循环:当CPU在持有RCU读侧临界区域时进入循环,阻止其他CPU取得进展,就会发生这种情况。
(2)CPU在中断被禁用时循环:如果CPU禁用了中断并进入循环,就会引起RCU CPU停滞告诫,因为中断对于RCU的进展是必须的。
(3)CPU在抢占被禁用时循环:当CPU禁用抢占并进入循环时,会导致RCU停滞,因为抢占对于RCU调度使命是必须的。
(4)CPU在底半部被禁用时循环:底半部是内核用于耽误工作的机制。如果CPU禁用了底半部并进入循环,就会阻止RCU实行必要的使命。
(5)对于非可抢占内核,在内核中的任何位置循环而没有调用schedule():在非可抢占内核中,如果CPU在没有调用schedule()函数的情况下循环,会导致RCU CPU停滞告诫。添加调用cond_resched()可以办理这个问题。
(6)引导过程中慢速控制台毗连:如果用于Linux引导的控制台毗连速度太慢无法跟上消息速率,就会导致RCU CPU停滞告诫,尤其是如果添加了额外的调试printk()语句。
(7)任何阻止RCU优雅期k线程运行的因素:如果有任何因素阻止RCU的优雅期k线程运行,会导致RCU CPU停滞告诫。这可能包括调度问题或影响RCU使命实行的其他因素。
(8)CPU密集型实时使命:在可抢占内核中,以较高优先级运行的CPU密集型实时使命可能会抢占RCU读侧临界区域中的低优先级使命。这会阻止RCU优雅期完成,导致RCU CPU停滞告诫。
(9)实行时间较长的周期性中断处理程序:如果周期性中断的处理程序实行时间凌驾一连两个中断之间的时间隔断,会阻止RCU的k线程和软中断处理程序运行,导致RCU CPU停滞告诫。
(10)在不同体系速度上测试工作负载:如果在速度较快的体系上使用调整过的停滞告诫超时时间测试工作负载,然后在速度较慢的体系上使用相同的超时时间运行,由于体系速度的差异,可能会引发RCU CPU停滞告诫。
(11)调度器时钟中断问题:在不处于dyntick-idle模式的CPU上关闭调度器时钟中断可能导致RCU CPU停滞告诫,尤其适用于CONFIG_NO_HZ_COMMON=n配置的内核。
(12)RCU实现中的错误:在某些情况下,RCU CPU停滞告诫可能表明RCU实现本身存在错误。
(13)硬件故障:尽管罕见,但硬件故障(比方,CPU故障)可能会导致RCU CPU停滞告诫,如果CPU变得无响应但不会立即导致体系崩溃。
当涉及到调试RCU相关问题时,有几种技术和工具可以提供资助:
RCU CPU停滞告诫:RCU的实现(如RCU、RCU-sched和RCU-tasks)在脱期期(grace period)举行时,如果某个CPU出现耽误,就会天生CPU停滞告诫。这些告诫表明体系可能存在问题,可以作为进一步观察的起点。
堆栈跟踪:检查堆栈跟踪通常可以揭示导致停滞的有问题函数。通过查看堆栈顶部附近的函数,可以确定造成耽误的代码。
比较堆栈跟踪:如果在一次长时间停滞期间观察到一系列停滞告诫,比较不同跟踪之间的堆栈跟踪可以资助确定造成停滞的详细函数。在所有跟踪中,保持在堆栈顶部附近的函数很可能是问题所在。
Ftrace:Ftrace是Linux内核中强大的跟踪框架,可资助诊断和调试RCU停滞。通过得当启用和配置Ftrace,可以跟踪实行流程并网络有关停滞期间RCU操纵的详细信息。
CONFIG_RCU_TRACE:内核配置选项CONFIG_RCU_TRACE可以启用RCU的附加调试功能。通过启用此选项,可以使用RCU的变乱跟踪功能,提供有关RCU活动的详细信息,有助于识别和办理与RCU相关的错误。
二、源码剖析

  1. /*
  2. * Called from the timer interrupt handler to charge one tick to the current
  3. * process.  user_tick is 1 if the tick is user time, 0 for system.
  4. */
  5. void update_process_times(int user_tick)
  6. {
  7.         struct task_struct *p = current;
  8.         /* Note: this timer irq context must be accounted for as well. */
  9.         account_process_tick(p, user_tick);
  10.         run_local_timers();
  11.         rcu_sched_clock_irq(user_tick);
  12. #ifdef CONFIG_IRQ_WORK
  13.         if (in_irq())
  14.                 irq_work_tick();
  15. #endif
  16.         scheduler_tick();
  17.         if (IS_ENABLED(CONFIG_POSIX_TIMERS))
  18.                 run_posix_cpu_timers();
  19. }
复制代码
这段代码是从定时器中断处理程序调用的函数,用于将一个时钟滴答计入当前进程的时间。user_tick参数表现该滴答是否属于用户时间(1表现是),0表现体系时间。
函数起首获取当前进程的task_struct结构体指针,并将其赋值给变量p。然后调用account_process_tick函数,将该滴答的时间计入当前进程的统计信息中,同时根据user_tick参数确定是用户时间还是体系时间。接着调用run_local_timers函数,运行本地定时器。然后调用rcu_sched_clock_irq函数,处理与RCU调度相关的时钟中断,同样根据user_tick参数确定是用户时间还是体系时间。
在定义了CONFIG_IRQ_WORK宏的情况下,如果当前处于中断上下文(in_irq函数返回真),则调用irq_work_tick函数,处理IRQ工作。紧接着调用scheduler_tick函数,实行调度器的时钟滴答处理。最后,如果启用了CONFIG_POSIX_TIMERS宏,在POSIX定时器支持的情况下,调用run_posix_cpu_timers函数,运行POSIX CPU定时器。
总体而言,该函数用于更新当前进程的时间统计信息,并处理与时钟相关的使命,如定时器、RCU调度、IRQ工作和调度器。
在这里我们主要关注 rcu_sched_clock_irq 函数:
  1. rcu_sched_clock_irq()
  2.         -->rcu_pending()
  3.                 -->check_cpu_stall()
  4.                         -->print_cpu_stall()
  5.                                 -->rcu_dump_cpu_stacks()
  6.                                         -->dump_cpu_task()
  7.                                                 -->sched_show_task()
  8.                                                         -->show_stack()
  9.                                                                 -->dump_backtrace()
复制代码
最后调用dump_backtrace打印函数调用栈。
此中print_cpu_stall函数表现RCU的CPU停滞检测器开始打印告诫信息:
  1. static void print_cpu_stall(void)
  2. {
  3.         int cpu;
  4.         unsigned long flags;
  5.         struct rcu_data *rdp = this_cpu_ptr(&rcu_data);
  6.         struct rcu_node *rnp = rcu_get_root();
  7.         long totqlen = 0;
  8.         /* Kick and suppress, if so configured. */
  9.         rcu_stall_kick_kthreads();
  10.         if (rcu_cpu_stall_suppress)
  11.                 return;
  12.         /*
  13.          * OK, time to rat on ourselves...
  14.          * See Documentation/RCU/stallwarn.txt for info on how to debug
  15.          * RCU CPU stall warnings.
  16.          */
  17.         pr_err("INFO: %s self-detected stall on CPU\n", rcu_state.name);
  18.         raw_spin_lock_irqsave_rcu_node(rdp->mynode, flags);
  19.         print_cpu_stall_info(smp_processor_id());
  20.         raw_spin_unlock_irqrestore_rcu_node(rdp->mynode, flags);
  21.         for_each_possible_cpu(cpu)
  22.                 totqlen += rcu_get_n_cbs_cpu(cpu);
  23.         pr_cont("\t(t=%lu jiffies g=%ld q=%lu)\n",
  24.                 jiffies - rcu_state.gp_start,
  25.                 (long)rcu_seq_current(&rcu_state.gp_seq), totqlen);
  26.         rcu_check_gp_kthread_starvation();
  27.         rcu_dump_cpu_stacks();
  28.         raw_spin_lock_irqsave_rcu_node(rnp, flags);
  29.         /* Rewrite if needed in case of slow consoles. */
  30.         if (ULONG_CMP_GE(jiffies, READ_ONCE(rcu_state.jiffies_stall)))
  31.                 WRITE_ONCE(rcu_state.jiffies_stall,
  32.                            jiffies + 3 * rcu_jiffies_till_stall_check() + 3);
  33.         raw_spin_unlock_irqrestore_rcu_node(rnp, flags);
  34.         panic_on_rcu_stall();
  35.         /*
  36.          * Attempt to revive the RCU machinery by forcing a context switch.
  37.          *
  38.          * A context switch would normally allow the RCU state machine to make
  39.          * progress and it could be we're stuck in kernel space without context
  40.          * switches for an entirely unreasonable amount of time.
  41.          */
  42.         set_tsk_need_resched(current);
  43.         set_preempt_need_resched();
  44. }
复制代码
三、调整RCU CPU停滞检测器的参数

rcuupdate.rcu_cpu_stall_suppress模块参数用于禁用RCU的CPU停滞检测器,该检测器用于检测导致RCU优雅期耽误的条件。此模块参数默认启用CPU停滞检测,但可以通过引导时参数或运行时通过sysfs举行覆盖。停滞检测器对于何种情况被认为是"过度耽误"的判断是由一组内核配置变量和cpp宏控制的:
(1)CONFIG_RCU_CPU_STALL_TIMEOUT
这个内核配置参数定义了RCU从脱期期(grace period)开始等待的时间,直到发出RCU CPU停滞告诫。
  1. # cat /boot/config-4.19.90-24.4.v2101.ky10.aarch64 | grep CONFIG_RCU_CPU_STALL_TIMEOUT
  2. CONFIG_RCU_CPU_STALL_TIMEOUT=60
复制代码
此配置参数可以通过/sys/module/rcupdate/parameters/rcu_cpu_stall_timeout在运行时举行更改,但是此参数仅在每个周期的开始处举行检查。因此,如果你在一个一连40秒的停滞中已经过了10秒,将此sysfs参数设置为(比如)5将收缩下一个停滞的超时时间或当前停滞的下一个告诫的时间(假设停滞的时间足够长)。它不会影响当前停滞的下一个告诫的时间。
通过/sys/module/rcupdate/parameters/rcu_cpu_stall_suppress可以完全启用或禁用停滞告诫消息。
(2)RCU_STALL_DELAY_DELTA
尽管lockdep工具非常有用,但它会增长一些开销。因此,在CONFIG_PROVE_RCU下,RCU_STALL_DELAY_DELTA宏答应额外耽误五秒钟才发出RCU CPU停滞告诫消息。(这是一个cpp宏,而不是内核配置参数)
备注:"cpp macro"指的是C/C++语言中的预处理宏(preprocessor macro)。C预处理器(C preprocessor)是一种在编译前对源代码举行预处理的工具。它会根据预定义的宏和指令,对源代码举行文本替换和条件编译等操纵。
在给出的形貌中,“RCU_STALL_DELAY_DELTA"和"RCU_STALL_RAT_DELAY"被提到是"cpp macro”,意味着它们是在编译前由预处理器处理的宏定义,而不是运行时可配置的内核参数。这些宏定义在代码中使用,在编译时会根据预定义的值举行相应的文本替换。
总之,"cpp macro"指的是C/C++语言中的预处理宏,它们在编译前被预处理器处理,并在编译时举行文本替换。
(3)RCU_STALL_RAT_DELAY
CPU停滞检测器实验使造成停滞的CPU打印自己的告诫消息,因为如许通常可以得到更高质量的堆栈跟踪。但是,如果造成停滞的CPU在RCU_STALL_RAT_DELAY指定的jiffies数内没有检测到自己的停滞,那么其他某个CPU将会举行投诉。这个耽误通常设置为两个jiffies。(这是一个cpp宏,而不是内核配置参数)
(4)rcupdate.rcu_task_stall_timeout
这个引导/sysfs参数控制RCU-tasks停滞告诫的隔断时间。值为零或更小的值会抑制RCU-tasks的停滞告诫。正值设置停滞告诫的隔断时间(以秒为单元)。RCU-tasks停滞告诫以以下行开始:
  1. INFO: rcu_tasks detected stalls on tasks:
复制代码
然后继续输出每个导致当前RCU-tasks优雅期停滞的使命的sched_show_task()输出。
通过调整这些参数,你可以根据你的需求来定制RCU CPU停滞检测器的行为。请留意,对这些参数的更改可能必要在引导时或运行时举行,而且应谨慎评估其对体系性能和调试能力的影响。
四、RCU的CPU停滞检测器"Splats"的表明

(1)
对于非RCU使命的RCU版本,在CPU检测到停滞时,它会打印类似以下的消息:
  1. INFO: rcu_sched detected stalls on CPUs/tasks:
  2. 2-...: (3 GPs behind) idle=06c/0/0 softirq=1453/1455 fqs=0
  3. 16-...: (0 ticks this GP) idle=81c/0/0 softirq=764/764 fqs=0
  4. (detected by 32, t=2603 jiffies, g=7075, q=625)
复制代码
这条消息表现CPU 32检测到CPU 2和CPU 16都导致了停滞,而且这个停滞影响了RCU-sched。这条消息通常背面会跟随每个CPU的堆栈转储。请留意,带有PREEMPT_RCU选项的构建版本可能由使命和CPU同时引起停滞,使命会用PID表现,比方,“P3421”。甚至可能同时由CPU和使命引起rcu_state停滞,这种情况下,引起问题的CPU和使命将在列表中全部列出。
CPU 2的"(3 GPs behind)“表现该CPU在过去的三个脱期期内没有与RCU焦点举行交互。相比之下,CPU 16的”(0 ticks this GP)"表现该CPU在当前停滞的优化期内没有吸取任何调度时钟中断。
消息中的"idle="部门打印了动态空闲状态。斜杠前面的十六进制数字是动态滴答计数器的低12位,如果CPU处于动态空闲模式,则该值为偶数;否则为奇数。两个斜杠之间的十六进制数字是嵌套值,如果在空闲循环中(如上所示),它将是一个小的非负数;否则将是一个非常大的正数。
消息中的"softirq="部门跟踪停滞的CPU实行的RCU软中断处理器的数量。斜杠前面的数字是该CPU在前次留意到一个脱期期开始时实行的软中断处理器数量,这可能是当前(停滞)优化期,也可能是之前的某个脱期期(比方,如果CPU长时间处于动态空闲模式)。斜杠背面的数字是从启动到当前时间实行的软中断处理器数量。如果这个背面的数字在重复的停滞告诫消息中保持稳定,可能是RCU的软中断处理器无法在该CPU上实行的情况。这可能发生在停滞的CPU被中断禁用自旋,或者在-rt内核中,如果一个高优先级进程饥饿RCU的软中断处理器。
"fqs="表现了自前次该CPU留意到优化期开始以来,脱期期内核线程在该CPU上举行的强制静默状态空闲/离线检测的次数。
"detected by"行指示哪个CPU检测到了停滞(在本例中是CPU 32),自脱期期开始以来经过的滴答数(在本例中是2603),优化期序列号(7075),以及所有CPU上列队的RCU回调的估计值(本例中为625)。
(2)
在具有CONFIG_RCU_FAST_NO_HZ的内核中,会打印更多信息
对于每个CPU:
  1. 0: (64628 ticks this GP) idle=dd5/3fffffffffffffff/0 softirq=82/543 last_accelerate: a345/d342 Nonlazy posted: ..D
复制代码
“last_accelerate:“打印的是当该CPU最后一次从rcu_needs_cpu()中调用rcu_try_advance_all_cbs()或从rcu_prepare_for_idle()中调用rcu_accelerate_cbs()时,jiffies计数器的低16位(十六进制表现)。“Nonlazy posted:“指示懒惰回调(lazy callback)的状态。如果在上一个空闲期开始时所有回调都是懒惰回调,则表现"l”,如果当前没有非懒惰回调,则表现"L”(在这两种情况下,如果不符合条件,则表现”.”),“D"表现启用了动态空闲处理(dyntick-idle)(如果通过"nohz=“内核引导参数禁用了动态空闲处理,则表现”.”)。
如果脱期期恰好在停滞告诫开始打印时结束,将出现虚伪的停滞告诫消息,此中将包括以下内容:
  1. INFO: Stall ended before state dump start
复制代码
这种情况很少见,但在实际情况下偶尔会发生。这种情况下,如果停滞告诫和脱期期初始化发生的方式相互影响,可能会标记为零滴答停滞(zero-jiffy stall)。请留意,要想完全消除这种误报,必要使用stop_machine()等方法,但这对于这种问题来说有些过度。
如果所有的CPU和使命都履历了静止状态(quiescent states),但脱期期仍旧未能结束,停滞告诫消息将包括类似以下的内容:
  1. 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节点结构的->qsmask字段的值,通常为零。
如果相关的脱期期kthread在停滞告诫之前无法运行,就像上面的"All QSes seen"行一样,将会打印以下额外的行:
  1. kthread starved for 23807 jiffies! g7075 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1 ->cpu=5
复制代码
如果 grace-period kthread无法得到CPU时间,纵然所有的CPU和使命都履历了所需的静止状态,也可能导致RCU CPU停滞告诫。"g"数字表现当前脱期期序列号,"f"前面是对grace-period kthread的->gp_flags命令,"RCU_GP_WAIT_FQS"指示kthread正在等待一个短暂的超时,"state"前面是task_struct ->state字段的值,"cpu"表现grace-period kthread前次在CPU 5上运行。
五、一个Stall的多个告诫

如果停滞一连的时间足够长,可能会打印多个停滞告诫消息。随着消息的增多,它们之间的时间隔断也会增长。详细而言,第一条消息和第二条消息之间的时间隔断将约莫是从停滞开始到第一条消息之间的隔断的三倍。
这种方法使得告诫消息之间的时间隔断逐渐增长,随着停滞的一连,告诫消息的表现变得更加分散和不频繁。如许做的目的是制止在停滞期间过多地向体系日志或控制台输出告诫消息,同时仍旧提供关于停滞的相关信息。
六、加急脱期期的停息告诫

如果快速脱期期(expedited grace period)检测到停滞,它将在dmesg中放置如下消息:
  1. 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”。
在同一次运行中,完全有可能同时看到来自平常脱期期和快速脱期期的停滞告诫。
参考资料

Linux 5.4.18
Documentation/RCU/stallwarn.txt

免责声明:如果侵犯了您的权益,请联系站长,我们会及时删除侵权内容,谢谢合作!更多信息从访问主页:qidao123.com:ToB企服之家,中国第一个企服评测及商务社交产业平台。
回复

使用道具 举报

0 个回复

正序浏览

快速回复

您需要登录后才可以回帖 登录 or 立即注册

本版积分规则

悠扬随风

金牌会员
这个人很懒什么都没写!

标签云

快速回复 返回顶部 返回列表