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]
Date:	Fri, 10 Sep 2010 15:34:53 +0200
From:	Peter Zijlstra <peterz@...radead.org>
To:	Don Zickus <dzickus@...hat.com>
Cc:	mingo@...e.hu, robert.richter@....com, gorcunov@...il.com,
	fweisbec@...il.com, linux-kernel@...r.kernel.org,
	ying.huang@...el.com, ming.m.lin@...el.com, yinghai@...nel.org,
	andi@...stfloor.org, eranian@...gle.com
Subject: Re: [PATCH 0/3 v2] nmi perf fixes

On Fri, 2010-09-10 at 13:41 +0200, Peter Zijlstra wrote:
> On Thu, 2010-09-02 at 15:07 -0400, Don Zickus wrote:
> > Fixes to allow unknown nmis to pass through the perf nmi handler instead
> > of being swallowed.  Contains patches that are already in Ingo's tree.  Added
> > here for completeness.  Based on ingo/tip

> Both Ingo and I are getting Dazed and confused on our AMD machines, it
> started before yesterday (that is, after backing out all my recent
> changes it still gets dazed), so I suspect this set.
> 
> I'll look at getting a trace of the thing, but if any of you has a
> bright idea...


           <...>-2155  [000]    57.298895: perf_event_nmi_handler: NMI-handled(1): 5735 0 0
           <...>-2155  [000]    57.298896: perf_event_nmi_handler: NMI-stop: 5735 0 0
           <...>-2155  [000]    57.298898: perf_event_nmi_handler: NMI: 5736 0 0
           <...>-2155  [000]    57.298898: x86_pmu_handle_irq: OVERFLOW: 0
           <...>-2155  [000]    57.298899: x86_pmu_handle_irq: HANDLED: 1
           <...>-2155  [000]    57.298901: x86_pmu_handle_irq: OVERFLOW: 2
           <...>-2155  [000]    57.298901: x86_pmu_handle_irq: OVERFLOW: 3
           <...>-2155  [000]    57.298902: perf_event_nmi_handler: NMI-handled(1): 5736 0 0
           <...>-2155  [000]    57.298903: perf_event_nmi_handler: NMI-stop: 5736 0 0
           <...>-2155  [000]    57.298905: perf_event_nmi_handler: NMI: 5737 0 0
           <...>-2155  [000]    57.298905: x86_pmu_handle_irq: OVERFLOW: 0
           <...>-2155  [000]    57.298906: x86_pmu_handle_irq: HANDLED: 1
           <...>-2155  [000]    57.298908: x86_pmu_handle_irq: OVERFLOW: 2
           <...>-2155  [000]    57.298908: x86_pmu_handle_irq: OVERFLOW: 3
           <...>-2155  [000]    57.298909: perf_event_nmi_handler: NMI-handled(1): 5737 0 0
           <...>-2155  [000]    57.298909: perf_event_nmi_handler: NMI-stop: 5737 0 0
           <...>-2155  [000]    57.298911: perf_event_nmi_handler: NMI: 5738 0 0
           <...>-2155  [000]    57.298912: x86_pmu_handle_irq: OVERFLOW: 0
           <...>-2155  [000]    57.298913: x86_pmu_handle_irq: HANDLED: 1
           <...>-2155  [000]    57.298915: x86_pmu_handle_irq: OVERFLOW: 2
           <...>-2155  [000]    57.298916: x86_pmu_handle_irq: OVERFLOW: 3
           <...>-2155  [000]    57.298916: perf_event_nmi_handler: NMI-handled(1): 5738 0 0
           <...>-2155  [000]    57.298917: perf_event_nmi_handler: NMI-stop: 5738 0 0
           <...>-2155  [000]    57.298919: perf_event_nmi_handler: NMI: 5739 0 0
           <...>-2155  [000]    57.298920: x86_pmu_handle_irq: OVERFLOW: 0
           <...>-2155  [000]    57.298921: x86_pmu_handle_irq: OVERFLOW: 2
           <...>-2155  [000]    57.298921: x86_pmu_handle_irq: OVERFLOW: 3
           <...>-2155  [000]    57.298922: perf_event_nmi_handler: NMI-handled(0): 5739 0 0
           <...>-2155  [000]    57.298923: perf_event_nmi_handler: NMI: 5739 0 0
           <...>-2155  [000]    57.298924: x86_pmu_handle_irq: OVERFLOW: 0
           <...>-2155  [000]    57.298925: x86_pmu_handle_irq: OVERFLOW: 2
           <...>-2155  [000]    57.298925: x86_pmu_handle_irq: OVERFLOW: 3
           <...>-2155  [000]    57.298926: perf_event_nmi_handler: NMI-handled(0): 5739 0 0
           <...>-2155  [000]    57.298927: perf_event_nmi_handler: NMI: 5739 0 0
           <...>-2155  [000]    57.298928: perf_event_nmi_handler: NMI-fail


Which suggests that 5738 was a good NMI, 5739 is an unhandled NMI, we
see it twice, once through DIE_NMI once through DIE_NMIUNKNOWN.

The problem seems to be that we don't tag it because handled isn't
larger than 1.

Its easy to reproduce on my opteron, simply run: 
  pref record -fg ./hackbench 50
a few times.

I'll try and reset the PMU on init to clear some of those OVERFLOW msgs
(hmm, maybe also read the ctrl word and check EN and INT before doing
the overflow check)..

---
 arch/x86/kernel/cpu/perf_event.c |   34 +++++++++++++++++++++++++++++++++-
 1 files changed, 33 insertions(+), 1 deletions(-)

diff --git a/arch/x86/kernel/cpu/perf_event.c b/arch/x86/kernel/cpu/perf_event.c
index de6569c..9aff608 100644
--- a/arch/x86/kernel/cpu/perf_event.c
+++ b/arch/x86/kernel/cpu/perf_event.c
@@ -1127,6 +1127,15 @@ static void x86_pmu_disable(struct perf_event *event)
 	perf_event_update_userpage(event);
 }
 
+static int pmc_overflow(int idx)
+{
+	u64 val;
+
+	rdmsrl(x86_pmu.perfctr + idx, val);
+
+	return !!(val & (1ULL << (x86_pmu.cntval_bits - 1)));
+}
+
 static int x86_pmu_handle_irq(struct pt_regs *regs)
 {
 	struct perf_sample_data data;
@@ -1141,6 +1150,8 @@ static int x86_pmu_handle_irq(struct pt_regs *regs)
 	cpuc = &__get_cpu_var(cpu_hw_events);
 
 	for (idx = 0; idx < x86_pmu.num_counters; idx++) {
+		if (pmc_overflow(idx))
+			trace_printk("OVERFLOW: %d\n", idx);
 		if (!test_bit(idx, cpuc->active_mask))
 			continue;
 
@@ -1154,6 +1165,7 @@ static int x86_pmu_handle_irq(struct pt_regs *regs)
 		/*
 		 * event overflow
 		 */
+		trace_printk("HANDLED: %d\n", idx);
 		handled++;
 		data.period	= event->hw.last_period;
 
@@ -1215,6 +1227,11 @@ perf_event_nmi_handler(struct notifier_block *self,
 	unsigned int this_nmi;
 	int handled;
 
+	trace_printk("NMI: %d %d %d\n",
+			percpu_read(irq_stat.__nmi_count),
+			__get_cpu_var(pmu_nmi).marked,
+			__get_cpu_var(pmu_nmi).handled);
+
 	if (!atomic_read(&active_events))
 		return NOTIFY_DONE;
 
@@ -1224,9 +1241,12 @@ perf_event_nmi_handler(struct notifier_block *self,
 		break;
 	case DIE_NMIUNKNOWN:
 		this_nmi = percpu_read(irq_stat.__nmi_count);
-		if (this_nmi != __get_cpu_var(pmu_nmi).marked)
+		if (this_nmi != __get_cpu_var(pmu_nmi).marked) {
+			trace_printk("NMI-fail\n");
 			/* let the kernel handle the unknown nmi */
 			return NOTIFY_DONE;
+		}
+		trace_printk("NMI-consume\n");
 		/*
 		 * This one is a PMU back-to-back nmi. Two events
 		 * trigger 'simultaneously' raising two back-to-back
@@ -1242,6 +1262,13 @@ perf_event_nmi_handler(struct notifier_block *self,
 	apic_write(APIC_LVTPC, APIC_DM_NMI);
 
 	handled = x86_pmu.handle_irq(args->regs);
+
+	trace_printk("NMI-handled(%d): %d %d %d\n",
+			handled,
+			percpu_read(irq_stat.__nmi_count),
+			__get_cpu_var(pmu_nmi).marked,
+			__get_cpu_var(pmu_nmi).handled);
+
 	if (!handled)
 		return NOTIFY_DONE;
 
@@ -1264,6 +1291,11 @@ perf_event_nmi_handler(struct notifier_block *self,
 		__get_cpu_var(pmu_nmi).handled	= handled;
 	}
 
+	trace_printk("NMI-stop: %d %d %d\n",
+			percpu_read(irq_stat.__nmi_count),
+			__get_cpu_var(pmu_nmi).marked,
+			__get_cpu_var(pmu_nmi).handled);
+
 	return NOTIFY_STOP;
 }
 

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ