New workloads can do large bursts of call_rcu_tasks() invocations in a short time period, followed by a quiet time period long enough to drain all of the callbacks, followed by another burst of call_rcu_tasks() invocations. This can cause RCU Tasks to switch back and forth between queuing callbacks only on CPU 0 (during quiet periods) and on all CPUs (during bursts).
Which is fine. Except for the fact that each cycle from CPU-0-only to all-CPUs queuing and back generates three console messages, one announcing the shift to all-CPUs queuing, another announcing the start of the shift back to CPU-0-only queuing, and the third announcing completion of this shift after an RCU grace period. And these console messages can overrun console-log communications channels and obscure other console-message-based debugging information. And the only known use for these console messages is debugging RCU Tasks itself. This commit therefore adds a rcupdate.rcu_task_collapse_debug module parameter that defaults to false (suppressing these console messages). Those debugging or otherwise playing with RCU Tasks callback queuing auto-adjustment can set this parameter to the value true. Reported-by: Breno Leitao <[email protected]> Reported-by: David Dai <[email protected]> Signed-off-by: Paul E. McKenney <[email protected]> --- Documentation/admin-guide/kernel-parameters.txt | 7 +++++++ kernel/rcu/tasks.h | 15 ++++++++++++--- 2 files changed, 19 insertions(+), 3 deletions(-) diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt index 6ebc1cd26c7c89..1a98b3b4ac34c7 100644 --- a/Documentation/admin-guide/kernel-parameters.txt +++ b/Documentation/admin-guide/kernel-parameters.txt @@ -6427,6 +6427,13 @@ Kernel parameters period to instead use normal non-expedited grace-period processing. + rcupdate.rcu_task_collapse_debug= [KNL] + Enable debugging prints that record when RCU Tasks + and RCU Tasks Trace expand to per-CPU callback + queuing and collapse back to CPU-0 queuing. + This is default-disabled due to the fact that + some workloads can make it quite noisy. + rcupdate.rcu_task_collapse_lim= [KNL] Set the maximum number of callbacks present at the beginning of a grace period that allows diff --git a/kernel/rcu/tasks.h b/kernel/rcu/tasks.h index 627295396cd91d..1150a390f37efa 100644 --- a/kernel/rcu/tasks.h +++ b/kernel/rcu/tasks.h @@ -178,6 +178,8 @@ static int rcu_task_contend_lim __read_mostly = 100; module_param(rcu_task_contend_lim, int, 0444); static int rcu_task_collapse_lim __read_mostly = 10; module_param(rcu_task_collapse_lim, int, 0444); +static bool rcu_task_collapse_debug __read_mostly = false; +module_param(rcu_task_collapse_debug, bool, 0644); static int rcu_task_lazy_lim __read_mostly = 32; module_param(rcu_task_lazy_lim, int, 0444); @@ -390,7 +392,8 @@ static void call_rcu_tasks_generic(struct rcu_head *rhp, rcu_callback_t func, WRITE_ONCE(rtp->percpu_enqueue_shift, 0); WRITE_ONCE(rtp->percpu_dequeue_lim, rcu_task_cpu_ids); smp_store_release(&rtp->percpu_enqueue_lim, rcu_task_cpu_ids); - pr_info("Switching %s to per-CPU callback queuing.\n", rtp->name); + if (data_race(rcu_task_collapse_debug)) + pr_info("Switching %s to per-CPU callback queuing.\n", rtp->name); } raw_spin_unlock_irqrestore(&rtp->cbs_gbl_lock, flags); } @@ -511,7 +514,9 @@ static int rcu_tasks_need_gpcb(struct rcu_tasks *rtp) smp_store_release(&rtp->percpu_enqueue_lim, 1); rtp->percpu_dequeue_gpseq = get_state_synchronize_rcu(); gpdone = false; - pr_info("Starting switch %s to CPU-0 callback queuing.\n", rtp->name); + if (data_race(rcu_task_collapse_debug)) + pr_info("Starting switch %s to CPU-0 callback queuing.\n", + rtp->name); } raw_spin_unlock_irqrestore(&rtp->cbs_gbl_lock, flags); } @@ -519,7 +524,9 @@ static int rcu_tasks_need_gpcb(struct rcu_tasks *rtp) raw_spin_lock_irqsave(&rtp->cbs_gbl_lock, flags); if (rtp->percpu_enqueue_lim < rtp->percpu_dequeue_lim) { WRITE_ONCE(rtp->percpu_dequeue_lim, 1); - pr_info("Completing switch %s to CPU-0 callback queuing.\n", rtp->name); + if (data_race(rcu_task_collapse_debug)) + pr_info("Completing switch %s to CPU-0 callback queuing.\n", + rtp->name); } if (rtp->percpu_dequeue_lim == 1) { for (cpu = rtp->percpu_dequeue_lim; cpu < rcu_task_cpu_ids; cpu++) { @@ -704,6 +711,8 @@ static void __init rcu_tasks_bootup_oddness(void) pr_info("\tTasks-RCU CPU stall info multiplier clamped to %d (rcu_task_stall_info_mult).\n", rtsimc); rcu_task_stall_info_mult = rtsimc; } + if (rcu_task_collapse_debug) + pr_info("\tTasks-RCU callback contend/collapse debug enabled.\n"); #endif /* #ifdef CONFIG_TASKS_RCU */ #ifdef CONFIG_TASKS_RCU pr_info("\tTrampoline variant of Tasks RCU enabled.\n");

