[PATCH 24/44] HACK: thunderbolt: Add scheduling delay to the trace

[Imre Deak]

From: Mika Westerberg <mika.westerberg at linux.intel.com>

Not-Signed-off-by: Mika Westerberg <mika.westerberg at linux.intel.com>
---
 drivers/thunderbolt/ctl.c   |  4 +++-
 drivers/thunderbolt/nhi.c   | 35 +++++++++++++++++++++++++++++++++++
 drivers/thunderbolt/trace.h | 12 ++++++++----
 include/linux/thunderbolt.h |  4 ++++
 4 files changed, 50 insertions(+), 5 deletions(-)

diff --git a/drivers/thunderbolt/ctl.c b/drivers/thunderbolt/ctl.c
index 95f296ca44cba..82af8cb97e3c9 100644
--- a/drivers/thunderbolt/ctl.c
+++ b/drivers/thunderbolt/ctl.c
@@ -434,6 +434,7 @@ static void tb_ctl_rx_callback(struct tb_ring *ring, struct ring_frame *frame,
 {
 	struct ctl_pkg *pkg = container_of(frame, typeof(*pkg), frame);
 	struct tb_cfg_request *req;
+	unsigned long delay;
 	__be32 crc32;
 
 	if (canceled)
@@ -496,7 +497,8 @@ static void tb_ctl_rx_callback(struct tb_ring *ring, struct ring_frame *frame,
 	 */
 	req = tb_cfg_request_find(pkg->ctl, pkg);
 
-	trace_tb_rx(frame->eof, pkg->buffer, frame->size, !req);
+	delay = (unsigned long)ktime_us_delta(ktime_get(), frame->received);
+	trace_tb_rx(frame->eof, pkg->buffer, frame->size, !req, delay);
 
 	if (req) {
 		if (req->copy(req, pkg))
diff --git a/drivers/thunderbolt/nhi.c b/drivers/thunderbolt/nhi.c
index e8a4623dc5319..3877fa47ddf0a 100644
--- a/drivers/thunderbolt/nhi.c
+++ b/drivers/thunderbolt/nhi.c
@@ -295,6 +295,16 @@ static void ring_work(struct work_struct *work)
 		frame = list_first_entry(&ring->in_flight, typeof(*frame),
 					 list);
 		list_move_tail(&frame->list, &done);
+
+		if (!frame->received) {
+			/*
+			 * Frame completed just after we added the
+			 * timestamps so use the timestamp of the last
+			 * interrupt.
+			 */
+			frame->received = ring->last_interrupt;
+		}
+
 		if (!ring->is_tx) {
 			frame->size = ring->descriptors[ring->tail].length;
 			frame->eof = ring->descriptors[ring->tail].eof;
@@ -327,6 +337,7 @@ int __tb_ring_enqueue(struct tb_ring *ring, struct ring_frame *frame)
 
 	spin_lock_irqsave(&ring->lock, flags);
 	if (ring->running) {
+		frame->received = 0;
 		list_add_tail(&frame->list, &ring->queue);
 		ring_write_descriptors(ring);
 	} else {
@@ -393,12 +404,36 @@ static void __ring_interrupt_mask(struct tb_ring *ring, bool mask)
 	iowrite32(val, ring->nhi->iobase + reg);
 }
 
+/* timestamp all completed frames */
+static void ring_timestamp_completed(struct tb_ring *ring)
+{
+	struct ring_frame *frame;
+	int tail = ring->tail;
+
+	ring->last_interrupt = ktime_get();
+
+	list_for_each_entry(frame, &ring->in_flight, list) {
+		if (!(ring->descriptors[tail].flags
+				& RING_DESC_COMPLETED))
+			break;
+
+		if (!frame->received)
+			frame->received = ring->last_interrupt;
+
+		tail = (tail + 1) % ring->size;
+		if (tail == ring->head)
+			break;
+	}
+}
+
 /* Both @nhi->lock and @ring->lock should be held */
 static void __ring_interrupt(struct tb_ring *ring)
 {
 	if (!ring->running)
 		return;
 
+	ring_timestamp_completed(ring);
+
 	if (ring->start_poll) {
 		__ring_interrupt_mask(ring, true);
 		ring->start_poll(ring->poll_data);
diff --git a/drivers/thunderbolt/trace.h b/drivers/thunderbolt/trace.h
index 47490cfcceceb..ec6b19a4ee1f1 100644
--- a/drivers/thunderbolt/trace.h
+++ b/drivers/thunderbolt/trace.h
@@ -150,22 +150,26 @@ DEFINE_EVENT(tb_raw, tb_event,
 );
 
 TRACE_EVENT(tb_rx,
-	TP_PROTO(u8 type, const void *data, size_t size, bool dropped),
-	TP_ARGS(type, data, size, dropped),
+	TP_PROTO(u8 type, const void *data, size_t size, bool dropped,
+		 unsigned long delay),
+	TP_ARGS(type, data, size, dropped, delay),
 	TP_STRUCT__entry(
 		__field(u8, type)
 		__field(size_t, size)
 		__dynamic_array(u32, data, size / 4)
 		__field(bool, dropped)
+		__field(unsigned long, delay)
 	),
 	TP_fast_assign(
 		__entry->type = type;
 		__entry->size = size / 4;
 		memcpy(__get_dynamic_array(data), data, size);
 		__entry->dropped = dropped;
+		__entry->delay = delay;
 	),
-	TP_printk("type=%s dropped=%u size=%zd %s",
-		  show_type_name(__entry->type), __entry->dropped, __entry->size,
+	TP_printk("type=%s dropped=%u size=%zd delay=%lu %s",
+		  show_type_name(__entry->type),
+		  __entry->dropped, __entry->size, __entry->delay,
 		  show_data(p, __entry->type, __get_dynamic_array(data),
 			    __entry->size)
 	)
diff --git a/include/linux/thunderbolt.h b/include/linux/thunderbolt.h
index 2c835e5c41f63..2885ca1ded2e6 100644
--- a/include/linux/thunderbolt.h
+++ b/include/linux/thunderbolt.h
@@ -528,6 +528,7 @@ struct tb_nhi {
  * @start_poll: Called when ring interrupt is triggered to start
  *		polling. Passing %NULL keeps the ring in interrupt mode.
  * @poll_data: Data passed to @start_poll
+ * @last_interrupt: Time when last interrupt occured.
  */
 struct tb_ring {
 	spinlock_t lock;
@@ -551,6 +552,7 @@ struct tb_ring {
 	u16 eof_mask;
 	void (*start_poll)(void *data);
 	void *poll_data;
+	ktime_t last_interrupt;
 };
 
 /* Leave ring interrupt enabled on suspend */
@@ -590,6 +592,7 @@ enum ring_desc_flags {
  * @flags: Flags for the frame (see &enum ring_desc_flags)
  * @eof: End of frame protocol defined field
  * @sof: Start of frame protocol defined field
+ * @received: Time when the frame was received from hardware
  */
 struct ring_frame {
 	dma_addr_t buffer_phy;
@@ -599,6 +602,7 @@ struct ring_frame {
 	u32 flags:12;
 	u32 eof:4;
 	u32 sof:4;
+	ktime_t received;
 };
 
 /* Minimum size for ring_rx */
-- 
2.39.2