spi: Provide trace points for message processing

Provide tracepoints for the lifecycle of a message from submission to
completion and for the active time for masters to help with performance
analysis of SPI I/O.

Signed-off-by: Mark Brown <broonie@linaro.org>

2 files changed, 109 insertions, 1 deletions

diff --git a/drivers/spi/spi.c b/drivers/spi/spi.c
index 9e039c6..8bef0c9 100644
--- a/drivers/spi/spi.c
+++ b/drivers/spi/spi.c
@@ -39,6 +39,9 @@
 #include <linux/ioport.h>
 #include <linux/acpi.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/spi.h>
+
 static void spidev_release(struct device *dev)
 {
 	struct spi_device	*spi = to_spi_device(dev);
@@ -557,6 +560,7 @@ static void spi_pump_messages(struct kthread_work *work)
 			pm_runtime_mark_last_busy(master->dev.parent);
 			pm_runtime_put_autosuspend(master->dev.parent);
 		}
+		trace_spi_master_idle(master);
 		return;
 	}
 
@@ -585,6 +589,9 @@ static void spi_pump_messages(struct kthread_work *work)
 		}
 	}
 
+	if (!was_busy)
+		trace_spi_master_busy(master);
+
 	if (!was_busy && master->prepare_transfer_hardware) {
 		ret = master->prepare_transfer_hardware(master);
 		if (ret) {
@@ -597,6 +604,8 @@ static void spi_pump_messages(struct kthread_work *work)
 		}
 	}
 
+	trace_spi_message_start(master->cur_msg);
+
 	ret = master->transfer_one_message(master, master->cur_msg);
 	if (ret) {
 		dev_err(&master->dev,
@@ -689,6 +698,8 @@ void spi_finalize_current_message(struct spi_master *master)
 	mesg->state = NULL;
 	if (mesg->complete)
 		mesg->complete(mesg->context);
+
+	trace_spi_message_done(mesg);
 }
 EXPORT_SYMBOL_GPL(spi_finalize_current_message);
 
@@ -1421,6 +1432,10 @@ static int __spi_async(struct spi_device *spi, struct spi_message *message)
 	struct spi_master *master = spi->master;
 	struct spi_transfer *xfer;
 
+	message->spi = spi;
+
+	trace_spi_message_submit(message);
+
 	if (list_empty(&message->transfers))
 		return -EINVAL;
 	if (!message->complete)
@@ -1520,7 +1535,6 @@ static int __spi_async(struct spi_device *spi, struct spi_message *message)
 		}
 	}
 
-	message->spi = spi;
 	message->status = -EINPROGRESS;
 	return master->transfer(spi, message);
 }
diff --git a/include/trace/events/spi.h b/include/trace/events/spi.h
new file mode 100644
index 0000000..a7b0907
--- /dev/null
+++ b/include/trace/events/spi.h
@@ -0,0 +1,94 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM spi
+
+#if !defined(_TRACE_SPI_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SPI_H
+
+#include <linux/ktime.h>
+#include <linux/tracepoint.h>
+
+DECLARE_EVENT_CLASS(spi_master,
+
+	TP_PROTO(struct spi_master *master),
+
+	TP_ARGS(master),
+
+	TP_STRUCT__entry(
+		__field(        int,           bus_num             )
+	),
+
+	TP_fast_assign(
+		__entry->bus_num = master->bus_num;
+	),
+
+	TP_printk("spi%d", (int)__entry->bus_num)
+
+);
+
+DEFINE_EVENT(spi_master, spi_master_idle,
+
+	TP_PROTO(struct spi_master *master),
+
+	TP_ARGS(master)
+
+);
+
+DEFINE_EVENT(spi_master, spi_master_busy,
+
+	TP_PROTO(struct spi_master *master),
+
+	TP_ARGS(master)
+
+);
+
+DECLARE_EVENT_CLASS(spi_message,
+
+	TP_PROTO(struct spi_message *msg),
+
+	TP_ARGS(msg),
+
+	TP_STRUCT__entry(
+		__field(        int,            bus_num         )
+		__field(        int,            chip_select     )
+		__field(        struct spi_message *,   msg     )
+	),
+
+	TP_fast_assign(
+		__entry->bus_num = msg->spi->master->bus_num;
+		__entry->chip_select = msg->spi->chip_select;
+		__entry->msg = msg;
+	),
+
+        TP_printk("spi%d.%d %p", (int)__entry->bus_num,
+		  (int)__entry->chip_select,
+		  (struct spi_message *)__entry->msg)
+);
+
+DEFINE_EVENT(spi_message, spi_message_submit,
+
+	TP_PROTO(struct spi_message *msg),
+
+	TP_ARGS(msg)
+
+);
+
+DEFINE_EVENT(spi_message, spi_message_start,
+
+	TP_PROTO(struct spi_message *msg),
+
+	TP_ARGS(msg)
+
+);
+
+DEFINE_EVENT(spi_message, spi_message_done,
+
+	TP_PROTO(struct spi_message *msg),
+
+	TP_ARGS(msg)
+
+);
+
+#endif /* _TRACE_POWER_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>