greybus: tracepoints: Add standard Linux tracepoint for TimeSync event

This patch adds a tracepoint to the TimeSync ISR, the purpose of which is
to indicate a TimeSync event has happened. This tracepoint can be enabled
by issuing the following command:

echo 1 > /sys/kernel/debug/tracing/events/greybus/gb_timesync_irq/enable

Synchronization looks like this:

 TIMESTAMP  FUNCTION
    |         |
147.865788: gb_timesync_irq: strobe 1/4 frame-time 2910076529
147.866781: gb_timesync_irq: strobe 2/4 frame-time 2910095689
147.867777: gb_timesync_irq: strobe 3/4 frame-time 2910114820
147.868791: gb_timesync_irq: strobe 4/4 frame-time 2910134038

A ping can be triggered like this:

cat /sys/kernel/debug/greybus/frame-time

And that ping looks like this:

 TIMESTAMP  FUNCTION
    |         |
147.934678: gb_timesync_irq: ping 4/4 frame-time 2911380356
169.280551: gb_timesync_irq: ping 4/4 frame-time 3321221069
Signed-off-by: Bryan O'Donoghue <bryan.odonoghue@linaro.org>
Reviewed-by: Vaibhav Hiremath <vaibhav.hiremath@linaro.org>
Acked-by: Alex Elder <elder@linaro.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@google.com>

drivers/staging/greybus/greybus_trace.h

@@ -488,6 +488,34 @@ DEFINE_HD_EVENT(gb_hd_in);
 
 #undef DEFINE_HD_EVENT
 
+/*
+ * Occurs on a TimeSync synchronization event or a TimeSync ping event.
+ */
+TRACE_EVENT(gb_timesync_irq,
+
+	TP_PROTO(u8 ping, u8 strobe, u8 count, u64 frame_time),
+
+	TP_ARGS(ping, strobe, count, frame_time),
+
+	TP_STRUCT__entry(
+		__field(u8, ping)
+		__field(u8, strobe)
+		__field(u8, count)
+		__field(u64, frame_time)
+	),
+
+	TP_fast_assign(
+		__entry->ping = ping;
+		__entry->strobe = strobe;
+		__entry->count = count;
+		__entry->frame_time = frame_time;
+	),
+
+	TP_printk("%s %d/%d frame-time %llu\n",
+		  __entry->ping ? "ping" : "strobe", __entry->strobe,
+		  __entry->count, __entry->frame_time)
+);
+
 #endif /* _TRACE_GREYBUS_H */
 
 /* This part must be outside protection */

drivers/staging/greybus/timesync.c

@@ -9,6 +9,7 @@
 #include <linux/debugfs.h>
 #include "greybus.h"
 #include "timesync.h"
+#include "greybus_trace.h"
 
 /*
  * Minimum inter-strobe value of one millisecond is chosen because it
@@ -974,17 +975,19 @@ void gb_timesync_irq(struct gb_timesync_svc *timesync_svc)
 {
 	unsigned long flags;
 	u64 strobe_time;
+	bool strobe_is_ping = true;
 
 	strobe_time = __gb_timesync_get_frame_time(timesync_svc);
 
 	spin_lock_irqsave(&timesync_svc->spinlock, flags);
 
 	if (timesync_svc->state == GB_TIMESYNC_STATE_PING) {
-		if (timesync_svc->capture_ping)
-			timesync_svc->ap_ping_frame_time = strobe_time;
-		goto done;
+		if (!timesync_svc->capture_ping)
+			goto done_nolog;
+		timesync_svc->ap_ping_frame_time = strobe_time;
+		goto done_log;
 	} else if (timesync_svc->state != GB_TIMESYNC_STATE_WAIT_SVC) {
-		goto done;
+		goto done_nolog;
 	}
 
 	timesync_svc->strobe_time[timesync_svc->strobe] = strobe_time;
@@ -993,7 +996,11 @@ void gb_timesync_irq(struct gb_timesync_svc *timesync_svc)
 		gb_timesync_set_state(timesync_svc,
 				      GB_TIMESYNC_STATE_AUTHORITATIVE);
 	}
-done:
+	strobe_is_ping = false;
+done_log:
+	trace_gb_timesync_irq(strobe_is_ping, timesync_svc->strobe,
+			      GB_TIMESYNC_MAX_STROBES, strobe_time);
+done_nolog:
 	spin_unlock_irqrestore(&timesync_svc->spinlock, flags);
 }
 EXPORT_SYMBOL(gb_timesync_irq);