ftrace: use a global counter for the global clock

no reason to muck about, just use a counter already.

---
 kernel/trace/trace_clock.c |   44 +++-----------------------------------------
 1 files changed, 3 insertions(+), 41 deletions(-)

index 6302747..1b79441 100644
@@ -68,48 +68,10 @@ u64 notrace trace_clock(void)
  * Used by plugins that need globally coherent timestamps.
  */
 
-/* keep prev_time and lock in the same cacheline. */
-static struct {
-	u64 prev_time;
-	arch_spinlock_t lock;
-} trace_clock_struct ____cacheline_aligned_in_smp =
-	{
-		.lock = (arch_spinlock_t)__ARCH_SPIN_LOCK_UNLOCKED,
-	};
+
+static atomic64_t trace_counter;
 
 u64 notrace trace_clock_global(void)
 {
-	unsigned long flags;
-	int this_cpu;
-	u64 now;
-
-	local_irq_save(flags);
-
-	this_cpu = raw_smp_processor_id();
-	now = cpu_clock(this_cpu);
-	/*
-	 * If in an NMI context then dont risk lockups and return the
-	 * cpu_clock() time:
-	 */
-	if (unlikely(in_nmi()))
-		goto out;
-
-	arch_spin_lock(&trace_clock_struct.lock);
-
-	/*
-	 * TODO: if this happens often then maybe we should reset
-	 * my_scd->clock to prev_time+1, to make sure
-	 * we start ticking with the local clock from now on?
-	 */
-	if ((s64)(now - trace_clock_struct.prev_time) < 0)
-		now = trace_clock_struct.prev_time + 1;
-
-	trace_clock_struct.prev_time = now;
-
-	arch_spin_unlock(&trace_clock_struct.lock);
-
- out:
-	local_irq_restore(flags);
-
-	return now;
+	return atomic64_add_return(1, &trace_counter);
 }

But some of us actually use the global clock as a clock ;)

How about this patch instead?

----

tracing: Add a counter clock for those that do not trust clocks

When debugging tight race conditions, it can be helpful to have a synchronized tracing method. Although in most cases the global clock provides this functionality, if timings is not the issue, it is more comforting to know that the order of events really happened in a precise order.

Instead of using a clock, add a "counter" that is simply an incrementing atomic 64bit counter that orders the events as they are perceived to happen.

The trace_clock_counter() is added from the attempt by Peter Zijlstra trying to convert the trace_clock_global() to it. I took Peter's counter code and made trace_clock_counter() instead, and added it to the choice of clocks. Just echo counter > /debug/tracing/trace_clock to activate it.

index 7a81303..4eb4902 100644
@@ -15,5 +15,6 @@
 extern u64 notrace trace_clock_local(void);
 extern u64 notrace trace_clock(void);
 extern u64 notrace trace_clock_global(void);
+extern u64 notrace trace_clock_counter(void);
 
 #endif /* _LINUX_TRACE_CLOCK_H */

index b419070..4b8df0d 100644
@@ -435,6 +435,7 @@ static struct {
 } trace_clocks[] = {
 	{ trace_clock_local,	"local" },
 	{ trace_clock_global,	"global" },
+	{ trace_clock_counter,	"counter" },
 };
 
 int trace_clock_id;

index 6302747..3947835 100644
@@ -113,3 +113,15 @@ u64 notrace trace_clock_global(void)
 
 	return now;
 }
+
+static atomic64_t trace_counter;
+
+/*
+ * trace_clock_counter(): simply an atomic counter.
+ * Use the trace_counter "counter" for cases where you do not care
+ * about timings, but are interested in strict ordering.
+ */
+u64 notrace trace_clock_counter(void)
+{
+	return atomic64_add_return(1, &trace_counter);
+}

Very much fine by me. Thanks!

Oh, fwiw I modified mine to increment by 1000 because we're showing us in the trace output, 1000 lines with the same 'time'-stamp is slightly confusing even though you know the order is absolutely right...

Or I could change it so that if counter clock is set, just show that field as a counter too.

-- Steve

Hmm, as I have other things to work on. I think I'll take your suggestion of the 1000 increment for now ;)

-- Steve

One wonders if the overhead can end up being enough to change the ordering, and possibly cause a heisenbug (most likely if the race condition involves one CPU doing something we're tracing, and another CPU doing something we are *not* tracing)...

If that's considered not an issue, feel free to stick this on it:

It will cause hickups, but shouldn't really change much of the ordering. If anything, it may synchronize more.

My use of logdev synchronized traces like this. But it actually caught a lot of race conditions. Really, it's about catching the ordering of what happens in a race condition, and having the tracer actually introduce synchronization helped in analysis. But true, as a heisenbug effect, enabling this tracer may make the bug go away.

Thanks, and yes, it is not too much of a concern. It just adds another option developers can use. Thus, if you are worried about cache line bouncing, just use the global or local clock, otherwise use the counter. Which I plan on documenting this side effect.

-- Steve