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");

Reply via email to