[ltt-dev] Kernel crashes when creating a trace

[Mathieu Desnoyers]

* Mathieu Desnoyers (mathieu.desnoyers at polymtl.ca) wrote:
> * Ashwin Tanugula (ashwin.tanugula at broadcom.com) wrote:
> > 
> > 
> > > >
> > > > Without "return 1;", it still hangs, I will enable lockdep and send you the log ASAP.
> > > >
> > 
> > > Oh ! I found the mistake. Erroneous "cmpxchg" in the 32-bit version of
> > > the trace clock. That should work without the return 1; now. Please try 0.174.
> > 
> > I am using patch-2.6.31.6-lttng-0.176, ltt-control-0.77-18112009 and lttv-0.12.23-18112009.
> > 
> > And I still see the hang without "return 1:"
> 
> OK. Can you please try with this patch applied on top of 0.176 ? This
> should be very close to mips64 which, AFAIK, should work and does not
> need this workaround to deal with 64-bit values. Sorry it's taking so
> long. It would help if I could get my hands on a MIPS32 board. More
> comments after the patch.

[snip snip]

I compared the mips code to the approach I took for intel (they were
quite similar) and found the discrepancy. Please ignore the previous
patch I just sent, and try this one instead:


mips32 fix trace clock spinlock (v2)

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers at polymtl.ca>
---
 arch/mips/kernel/trace-clock.c |   71 ++++++++++++++++++++---------------------
 1 file changed, 36 insertions(+), 35 deletions(-)

Index: linux-2.6-lttng/arch/mips/kernel/trace-clock.c
===================================================================
--- linux-2.6-lttng.orig/arch/mips/kernel/trace-clock.c	2009-11-18 16:47:48.000000000 -0500
+++ linux-2.6-lttng/arch/mips/kernel/trace-clock.c	2009-11-18 17:16:59.000000000 -0500
@@ -18,37 +18,11 @@ static DEFINE_SPINLOCK(async_tsc_lock);
 static int async_tsc_refcount;	/* Number of readers */
 static int async_tsc_enabled;	/* Async TSC enabled on all online CPUs */
 
-/*
- * Support for architectures with non-sync TSCs.
- * When the local TSC is discovered to lag behind the highest TSC counter, we
- * increment the TSC count of an amount that should be, ideally, lower than the
- * execution time of this routine, in cycles : this is the granularity we look
- * for : we must be able to order the events.
- */
-
-#if BITS_PER_LONG == 64
-notrace u64 trace_clock_async_tsc_read(void)
+#if (BITS_PER_LONG == 64)
+static inline u64 trace_clock_cmpxchg64(u64 *ptr, u64 old, u64 new)
 {
-	u64 new_tsc, last_tsc;
-
-	WARN_ON(!async_tsc_refcount || !async_tsc_enabled);
-	new_tsc = trace_clock_read_synthetic_tsc();
-	do {
-		last_tsc = trace_clock_last_tsc;
-		if (new_tsc < last_tsc)
-			new_tsc = last_tsc + TRACE_CLOCK_MIN_PROBE_DURATION;
-		/*
-		 * If cmpxchg fails with a value higher than the new_tsc, don't
-		 * retry : the value has been incremented and the events
-		 * happened almost at the same time.
-		 * We must retry if cmpxchg fails with a lower value :
-		 * it means that we are the CPU with highest frequency and
-		 * therefore MUST update the value.
-		 */
-	} while (cmpxchg64(&trace_clock_last_tsc, last_tsc, new_tsc) < new_tsc);
-	return new_tsc;
+	return cmpxchg64(ptr, old, new);
 }
-EXPORT_SYMBOL_GPL(trace_clock_async_tsc_read);
 #else
 /*
  * Emulate an atomic 64-bits update with a spinlock.
@@ -59,6 +33,9 @@ EXPORT_SYMBOL_GPL(trace_clock_async_tsc_
 static raw_spinlock_t trace_clock_lock =
 	(raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
 
+/*
+ * Must be called under irqoff+spinlock on MIPS32.
+ */
 static inline u64 trace_clock_cmpxchg64(u64 *ptr, u64 old, u64 new)
 {
 	u64 val;
@@ -68,18 +45,41 @@ static inline u64 trace_clock_cmpxchg64(
 		*ptr = new;
 	return val;
 }
+#endif
+
+/*
+ * Must be called under irqoff+spinlock on MIPS32.
+ */
+static cycles_t read_last_tsc(void)
+{
+	return trace_clock_last_tsc;
+}
+
+/*
+ * Support for architectures with non-sync TSCs.
+ * When the local TSC is discovered to lag behind the highest TSC counter, we
+ * increment the TSC count of an amount that should be, ideally, lower than the
+ * execution time of this routine, in cycles : this is the granularity we look
+ * for : we must be able to order the events.
+ *
+ * MIPS32 does not have atomic 64-bit updates. Emulate it with irqoff+spinlock.
+ */
 
 notrace u64 trace_clock_async_tsc_read(void)
 {
 	u64 new_tsc, last_tsc;
+#if (BITS_PER_LONG == 32)
 	unsigned long flags;
 
-	WARN_ON(!async_tsc_refcount || !async_tsc_enabled);
 	local_irq_save(flags);
 	__raw_spin_lock(&trace_clock_lock);
+#endif
+
+	WARN_ON(!async_tsc_refcount || !async_tsc_enabled);
 	new_tsc = trace_clock_read_synthetic_tsc();
+	barrier();
+	last_tsc = read_last_tsc();
 	do {
-		last_tsc = trace_clock_last_tsc;
 		if (new_tsc < last_tsc)
 			new_tsc = last_tsc + TRACE_CLOCK_MIN_PROBE_DURATION;
 		/*
@@ -90,15 +90,16 @@ notrace u64 trace_clock_async_tsc_read(v
 		 * it means that we are the CPU with highest frequency and
 		 * therefore MUST update the value.
 		 */
-	} while (trace_clock_cmpxchg64(&trace_clock_last_tsc, last_tsc,
-				       new_tsc) < new_tsc);
+		last_tsc = trace_clock_cmpxchg64(&trace_clock_last_tsc,
+						 last_tsc, new_tsc);
+	} while (unlikely(last_tsc < new_tsc));
+#if (BITS_PER_LONG == 32)
 	__raw_spin_unlock(&trace_clock_lock);
 	local_irq_restore(flags);
+#endif
 	return new_tsc;
 }
 EXPORT_SYMBOL_GPL(trace_clock_async_tsc_read);
-#endif
-
 
 static void update_timer_ipi(void *info)
 {


-- 
Mathieu Desnoyers
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68