[PATCH 2/8] nvme-tcp: io_work stall debugging

[Hannes Reinecke]

From: Hannes Reinecke <hare at suse.de>

Add a debug message when the io workqueue exceeds the latency target
given by 'deadline'.

Signed-off-by: Hannes Reinecke <hare at kernel.org>
---
 drivers/nvme/host/tcp.c | 20 ++++++++++++++++----
 1 file changed, 16 insertions(+), 4 deletions(-)

diff --git a/drivers/nvme/host/tcp.c b/drivers/nvme/host/tcp.c
index 3cf9a9abb0e0..7876bf7d2fac 100644
--- a/drivers/nvme/host/tcp.c
+++ b/drivers/nvme/host/tcp.c
@@ -1282,13 +1282,14 @@ static void nvme_tcp_io_work(struct work_struct *w)
 {
 	struct nvme_tcp_queue *queue =
 		container_of(w, struct nvme_tcp_queue, io_work);
-	u64 start = ktime_to_us(ktime_get());
+	u64 start = ktime_to_us(ktime_get()), overrun;
 	u64 tx_deadline = start + deadline;
+	bool pending = false;
 
 	do {
-		bool pending = false;
 		int result;
 
+		pending = false;
 		if (mutex_trylock(&queue->send_mutex)) {
 			result = nvme_tcp_try_send(queue);
 			mutex_unlock(&queue->send_mutex);
@@ -1304,12 +1305,23 @@ static void nvme_tcp_io_work(struct work_struct *w)
 		else if (unlikely(result < 0))
 			return;
 
-		if (!pending || !queue->rd_enabled)
+		if (!queue->rd_enabled)
 			return;
+		if (!pending)
+			goto check;
 
 	} while (ktime_to_us(ktime_get()) < tx_deadline); /* quota is exhausted */
 
-	queue_work_on(queue->io_cpu, nvme_tcp_wq, &queue->io_work);
+check:
+	overrun = ktime_to_us(ktime_get()) - start;
+	if (overrun > 10 * deadline) {
+		dev_dbg(queue->ctrl->ctrl.device,
+			"queue %d: stall (%llu msecs)%s%s\n",
+			nvme_tcp_queue_id(queue), div_u64(overrun, 1000),
+			list_empty(&queue->send_list) ? " empty" : "", queue->request ? " pending" : "");
+	}
+	if (pending)
+		queue_work_on(queue->io_cpu, nvme_tcp_wq, &queue->io_work);
 }
 
 static void nvme_tcp_free_crypto(struct nvme_tcp_queue *queue)
-- 
2.35.3