[PATCH] nvme-tcp: add additional info for nvme_tcp_timeout log

[Sagi Grimberg]

> From: Amit Engel <Amit.Engel at dell.com>
> 
> This provides additional details about the rq/cmd that is timed out

Please add an example print of the timeout log msg.

> 
> Signed-off-by: Amit Engel <Amit.Engel at dell.com>
> ---
>   drivers/nvme/host/tcp.c | 7 +++++--
>   1 file changed, 5 insertions(+), 2 deletions(-)
> 
> diff --git a/drivers/nvme/host/tcp.c b/drivers/nvme/host/tcp.c
> index 1eed0fc26b3a..5abaff5d6f6e 100644
> --- a/drivers/nvme/host/tcp.c
> +++ b/drivers/nvme/host/tcp.c
> @@ -2277,8 +2277,11 @@ static enum blk_eh_timer_return nvme_tcp_timeout(struct request *rq)
>   	struct nvme_tcp_cmd_pdu *pdu = req->pdu;
>   
>   	dev_warn(ctrl->device,
> -		"queue %d: timeout request %#x type %d\n",
> -		nvme_tcp_queue_id(req->queue), rq->tag, pdu->hdr.type);
> +		"queue %d: cntlid %u timeout request %#x type %d cid %u opcode %#x "
> +		"start time %lluns io start time %lluns request timeout %ums\n",
> +		nvme_tcp_queue_id(req->queue), ctrl->cntlid, rq->tag, pdu->hdr.type,
> +		pdu->cmd.common.command_id, pdu->cmd.common.opcode,
> +		ktime_sub_ns(ktime_get(), rq->start_time_ns), ktime_sub_ns(ktime_get(), rq->io_start_time_ns), jiffies_to_msecs(rq->timeout));

You can get the cntlid from the controller device name which appears in
dev_warn, no need for it here.

Why are you printing the timeout value (in ktime)? What info does it
add? You can see the relative time in the log and you know what the
io timeout is (30 seconds before by default)...

You can also easily retrieve the cid from the tag (lower 12 bits).

The nvme opcode is fine to add...

>   
>   	if (ctrl->state != NVME_CTRL_LIVE) {
>   		/*