A bunch of bugzillas have complained how noisy the nmi_watchdog is during
boot-up especially with its expected failure cases (like virt and bios
resource contention).
This is my attempt to quiet them down and keep it less confusing for the end
user. What I did is print the message for cpu0 and save it for future
comparisons. If future cpus have an identical message as cpu0, then don't
print the redundant info. However, if a future cpu has a different message,
happily print that loudly.
Before the change, you would see something like:
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: Intel(R) Core(TM)2 Quad CPU Q9550 @ 2.83GHz stepping 0a
Performance Events: PEBS fmt0+, Core2 events, Intel PMU driver.
... version: 2
... bit width: 40
... generic registers: 2
... value mask: 000000ffffffffff
... max period: 000000007fffffff
... fixed-purpose events: 3
... event mask: 0000000700000003
NMI watchdog enabled, takes one hw-pmu counter.
Booting Node 0, Processors #1
NMI watchdog enabled, takes one hw-pmu counter.
#2
NMI watchdog enabled, takes one hw-pmu counter.
#3 Ok.
NMI watchdog enabled, takes one hw-pmu counter.
Brought up 4 CPUs
Total of 4 processors activated (22607.24 BogoMIPS).
After the change, it is simplified to:
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: Intel(R) Core(TM)2 Quad CPU Q9550 @ 2.83GHz stepping 0a
Performance Events: PEBS fmt0+, Core2 events, Intel PMU driver.
... version: 2
... bit width: 40
... generic registers: 2
... value mask: 000000ffffffffff
... max period: 000000007fffffff
... fixed-purpose events: 3
... event mask: 0000000700000003
NMI watchdog enabled, takes one hw-pmu counter.
Booting Node 0, Processors #1 #2 #3 Ok.
Brought up 4 CPUs
V2: little changes based on Joe Perches' feedback
V3: printk cleanup based on Ingo's feedback; checkpatch fix
Reported-and-tested-by: Nathan Zimmer <[email protected]>
Signed-off-by: Don Zickus <[email protected]>
---
kernel/watchdog.c | 21 ++++++++++++++++++++-
1 files changed, 20 insertions(+), 1 deletions(-)
diff --git a/kernel/watchdog.c b/kernel/watchdog.c
index e5e1d85..74b1e27 100644
--- a/kernel/watchdog.c
+++ b/kernel/watchdog.c
@@ -377,6 +377,13 @@ static int watchdog_nmi_enable(int cpu)
struct perf_event_attr *wd_attr;
struct perf_event *event = per_cpu(watchdog_ev, cpu);
+ /*
+ * People like the simple clean cpu node info on boot.
+ * Reduce the watchdog noise by only printing messages
+ * that are different from what cpu0 displayed.
+ */
+ static unsigned long cpu0_err;
+
/* is it already setup and enabled? */
if (event && event->state > PERF_EVENT_STATE_OFF)
goto out;
@@ -390,11 +397,23 @@ static int watchdog_nmi_enable(int cpu)
/* Try to register using hardware perf events */
event = perf_event_create_kernel_counter(wd_attr, cpu, NULL, watchdog_overflow_callback, NULL);
+
+ /* save cpu0 error for future comparision */
+ if (cpu == 0 && IS_ERR(event))
+ cpu0_err = PTR_ERR(event);
+
if (!IS_ERR(event)) {
- pr_info("enabled, takes one hw-pmu counter.\n");
+ /* only print for cpu0 or different than cpu0 */
+ if (cpu == 0 || cpu0_err) {
+ pr_info("enabled on all CPUs, permanently consumes ");
+ pr_cont("one hw-PMU counter.\n");
+ }
goto out_save;
}
+ /* skip displaying the same error again */
+ if (cpu > 0 && (PTR_ERR(event) == cpu0_err))
+ return PTR_ERR(event);
/* vary the KERN level based on the returned errno */
if (PTR_ERR(event) == -EOPNOTSUPP)
--
1.7.7.6
On Mon, 2012-06-11 at 16:04 -0400, Don Zickus wrote:
> A bunch of bugzillas have complained how noisy the nmi_watchdog is during
> boot-up especially with its expected failure cases (like virt and bios
> resource contention).
[]
> diff --git a/kernel/watchdog.c b/kernel/watchdog.c
[]
> @@ -390,11 +397,23 @@ static int watchdog_nmi_enable(int cpu)
[]
> if (!IS_ERR(event)) {
> - pr_info("enabled, takes one hw-pmu counter.\n");
> + /* only print for cpu0 or different than cpu0 */
> + if (cpu == 0 || cpu0_err) {
> + pr_info("enabled on all CPUs, permanently consumes ");
> + pr_cont("one hw-PMU counter.\n");
Don't worry about formats exceeding 80 column please.
Don't break up pr_info into multiple bits either.
pr_info("enabled on all cpus, permanently consumes one hw-PMU counter\n");
On Mon, Jun 11, 2012 at 01:56:50PM -0700, Joe Perches wrote:
> On Mon, 2012-06-11 at 16:04 -0400, Don Zickus wrote:
> > A bunch of bugzillas have complained how noisy the nmi_watchdog is during
> > boot-up especially with its expected failure cases (like virt and bios
> > resource contention).
> []
> > diff --git a/kernel/watchdog.c b/kernel/watchdog.c
> []
> > @@ -390,11 +397,23 @@ static int watchdog_nmi_enable(int cpu)
> []
> > if (!IS_ERR(event)) {
> > - pr_info("enabled, takes one hw-pmu counter.\n");
> > + /* only print for cpu0 or different than cpu0 */
> > + if (cpu == 0 || cpu0_err) {
> > + pr_info("enabled on all CPUs, permanently consumes ");
> > + pr_cont("one hw-PMU counter.\n");
>
> Don't worry about formats exceeding 80 column please.
> Don't break up pr_info into multiple bits either.
>
> pr_info("enabled on all cpus, permanently consumes one hw-PMU counter\n");
Ok. Thanks.
Cheers,
Don
On Mon, Jun 11, 2012 at 04:04:10PM -0400, Don Zickus wrote:
> A bunch of bugzillas have complained how noisy the nmi_watchdog is during
> boot-up especially with its expected failure cases (like virt and bios
> resource contention).
>
> This is my attempt to quiet them down and keep it less confusing for the end
> user. What I did is print the message for cpu0 and save it for future
> comparisons. If future cpus have an identical message as cpu0, then don't
> print the redundant info. However, if a future cpu has a different message,
> happily print that loudly.
Would anyone object to compressing these lines too ?
> ... version: 2
> ... bit width: 40
> ... generic registers: 2
> ... value mask: 000000ffffffffff
> ... max period: 000000007fffffff
> ... fixed-purpose events: 3
> ... event mask: 0000000700000003
That's a lot of wasted space, that could just as easily take up two lines
without losing readability.
untested, but something like the below patch..
Dave
diff --git a/arch/x86/kernel/cpu/perf_event.c b/arch/x86/kernel/cpu/perf_event.c
index c4706cf..68e83ad 100644
--- a/arch/x86/kernel/cpu/perf_event.c
+++ b/arch/x86/kernel/cpu/perf_event.c
@@ -1389,13 +1389,13 @@ static int __init init_hw_perf_events(void)
x86_pmu.attr_rdpmc = 1; /* enable userspace RDPMC usage by default */
x86_pmu_format_group.attrs = x86_pmu.format_attrs;
- pr_info("... version: %d\n", x86_pmu.version);
- pr_info("... bit width: %d\n", x86_pmu.cntval_bits);
- pr_info("... generic registers: %d\n", x86_pmu.num_counters);
- pr_info("... value mask: %016Lx\n", x86_pmu.cntval_mask);
- pr_info("... max period: %016Lx\n", x86_pmu.max_period);
- pr_info("... fixed-purpose events: %d\n", x86_pmu.num_counters_fixed);
- pr_info("... event mask: %016Lx\n", x86_pmu.intel_ctrl);
+ pr_info("... version: %d ", x86_pmu.version);
+ pr_info("bit width: %d ", x86_pmu.cntval_bits);
+ pr_info("generic registers: %d\n", x86_pmu.num_counters);
+ pr_info("... value mask: %016Lx ", x86_pmu.cntval_mask);
+ pr_info("max period: %016Lx ", x86_pmu.max_period);
+ pr_info("fixed-purpose events: %d ", x86_pmu.num_counters_fixed);
+ pr_info("event mask: %016Lx\n", x86_pmu.intel_ctrl);
perf_pmu_register(&pmu, "cpu", PERF_TYPE_RAW);
perf_cpu_notifier(x86_pmu_notifier);
On Mon, 2012-06-11 at 17:12 -0400, Dave Jones wrote:
[]
> Would anyone object to compressing these lines too ?
>
> > ... version: 2
> > ... bit width: 40
> > ... generic registers: 2
> > ... value mask: 000000ffffffffff
> > ... max period: 000000007fffffff
> > ... fixed-purpose events: 3
> > ... event mask: 0000000700000003
[]
> diff --git a/arch/x86/kernel/cpu/perf_event.c b/arch/x86/kernel/cpu/perf_event.c
[]
> @@ -1389,13 +1389,13 @@ static int __init init_hw_perf_events(void)
> x86_pmu.attr_rdpmc = 1; /* enable userspace RDPMC usage by default */
> x86_pmu_format_group.attrs = x86_pmu.format_attrs;
>
> - pr_info("... version: %d\n", x86_pmu.version);
> - pr_info("... bit width: %d\n", x86_pmu.cntval_bits);
> - pr_info("... generic registers: %d\n", x86_pmu.num_counters);
> - pr_info("... value mask: %016Lx\n", x86_pmu.cntval_mask);
> - pr_info("... max period: %016Lx\n", x86_pmu.max_period);
> - pr_info("... fixed-purpose events: %d\n", x86_pmu.num_counters_fixed);
> - pr_info("... event mask: %016Lx\n", x86_pmu.intel_ctrl);
> + pr_info("... version: %d ", x86_pmu.version);
> + pr_info("bit width: %d ", x86_pmu.cntval_bits);
> + pr_info("generic registers: %d\n", x86_pmu.num_counters);
> + pr_info("... value mask: %016Lx ", x86_pmu.cntval_mask);
> + pr_info("max period: %016Lx ", x86_pmu.max_period);
> + pr_info("fixed-purpose events: %d ", x86_pmu.num_counters_fixed);
> + pr_info("event mask: %016Lx\n", x86_pmu.intel_ctrl);
That wouldn't work.
Every pr_<level> other than pr_cont will always be start a new line.
You want pr_cont for each of these other than the ... ones.
It'd be better too just to use 2 pr_info lines like:
pr_info("... version: %d bit width: %d generic registers: %d\n",
x86_pmu.version, x86_pmu.cntval_bits, x86_pmu.num_counters);
pr_info("... value mask: %016Lx max period: %016Lx fixed-purpose events: %d event mask: %016Lx\n",
x86_pmu.cntval_mask, x86_pmu.max_period,
x86_pmu.num_counters_fixed, x86_pmu.intel_ctrl);
* Dave Jones <[email protected]> wrote:
> On Mon, Jun 11, 2012 at 04:04:10PM -0400, Don Zickus wrote:
> > A bunch of bugzillas have complained how noisy the nmi_watchdog is during
> > boot-up especially with its expected failure cases (like virt and bios
> > resource contention).
> >
> > This is my attempt to quiet them down and keep it less confusing for the end
> > user. What I did is print the message for cpu0 and save it for future
> > comparisons. If future cpus have an identical message as cpu0, then don't
> > print the redundant info. However, if a future cpu has a different message,
> > happily print that loudly.
>
> Would anyone object to compressing these lines too ?
>
> > ... version: 2
> > ... bit width: 40
> > ... generic registers: 2
> > ... value mask: 000000ffffffffff
> > ... max period: 000000007fffffff
> > ... fixed-purpose events: 3
> > ... event mask: 0000000700000003
>
> That's a lot of wasted space, that could just as easily take
> up two lines without losing readability.
Yeah, we can do that, this was early debug code.
I'd suggest compressing it further, to a single line, to
something like:
... ver: 2, regs: 2/3, bits: 40, masks: 0xffffffffff/0x700000003/0x7fffffff
Thanks,
Ingo