linux-kernel - [PATCH 2/3] rcu: print first CPU on expedited stall line

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-Id: <20221219202910.3063036-3-elliott@hpe.com>
Date:   Mon, 19 Dec 2022 14:29:09 -0600
From:   Robert Elliott <elliott@....com>
To:     herbert@...dor.apana.org.au, davem@...emloft.net,
        paulmck@...nel.org, frederic@...nel.org, quic_neeraju@...cinc.com,
        josh@...htriplett.org
Cc:     linux-crypto@...r.kernel.org, rcu@...r.kernel.org,
        linux-kernel@...r.kernel.org, Robert Elliott <elliott@....com>
Subject: [PATCH 2/3] rcu: print first CPU on expedited stall line

Include the first CPU number in the first pr_err() call reporting
an expedited stall warning.

Printing the CPU numbers with subsequent pr_cont() calls can
result in the prints being many lines away or being dropped entirely
in a busy system. This change ensures there is indication of at
least one of the CPUs with the problem with the original message.

Before (if prints are interspersed with other prints):
  rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: {
  13-....
  } 32 jiffies s: 6685 root: 0x1/.

After:
  rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: {13-....
  } 32 jiffies s: 6685 root: 0x1/.

Signed-off-by: Robert Elliott <elliott@....com>
---
 kernel/rcu/tree_exp.h | 22 +++++++++++++++-------
 1 file changed, 15 insertions(+), 7 deletions(-)

diff --git a/kernel/rcu/tree_exp.h b/kernel/rcu/tree_exp.h
index ed6c3cce28f2..ade6a18e6c07 100644
--- a/kernel/rcu/tree_exp.h
+++ b/kernel/rcu/tree_exp.h
@@ -624,8 +624,6 @@ static void synchronize_rcu_expedited_wait(void)
 		if (rcu_stall_is_suppressed())
 			continue;
 		trace_rcu_stall_warning(rcu_state.name, TPS("ExpeditedStall"));
-		pr_err("INFO: %s detected expedited stalls on CPUs/tasks: {",
-		       rcu_state.name);
 		ndetected = 0;
 		rcu_for_each_leaf_node(rnp) {
 			ndetected += rcu_print_task_exp_stall(rnp);
@@ -637,11 +635,21 @@ static void synchronize_rcu_expedited_wait(void)
 					continue;
 				ndetected++;
 				rdp = per_cpu_ptr(&rcu_data, cpu);
-				pr_cont(" %d-%c%c%c%c", cpu,
-					"O."[!!cpu_online(cpu)],
-					"o."[!!(rdp->grpmask & rnp->expmaskinit)],
-					"N."[!!(rdp->grpmask & rnp->expmaskinitnext)],
-					"D."[!!(rdp->cpu_no_qs.b.exp)]);
+				// print the prefix and the first CPU number together
+				// under heavy load, the pr_cont prints can be far away or dropped
+				if (ndetected == 1)
+					pr_err("INFO: %s detected expedited stalls on CPUs/tasks: {%d-%c%c%c%c",
+					       rcu_state.name, cpu,
+					       "O."[!!cpu_online(cpu)],
+					       "o."[!!(rdp->grpmask & rnp->expmaskinit)],
+					       "N."[!!(rdp->grpmask & rnp->expmaskinitnext)],
+					       "D."[!!(rdp->cpu_no_qs.b.exp)]);
+				else
+					pr_cont(" %d-%c%c%c%c", cpu,
+						"O."[!!cpu_online(cpu)],
+						"o."[!!(rdp->grpmask & rnp->expmaskinit)],
+						"N."[!!(rdp->grpmask & rnp->expmaskinitnext)],
+						"D."[!!(rdp->cpu_no_qs.b.exp)]);
 			}
 		}
 		pr_cont(" } %lu jiffies s: %lu root: %#lx/%c\n",
-- 
2.38.1