2018-06-26 16:00:53

by Johannes Thumshirn

[permalink] [raw]
Subject: [PATCH v4 0/2] nvme: add controller id and disk name to tracepoints

Patch one is a preparation patch from Sagi and caches the nvme_ctrl in
the nvme_request. This is not only useful for the tracepoints but for
further development as well.

The second patch adds the controller IDs and if applicable the disk
name to the tracepoints so we can distinguish between the individual
controllers and disks.

The patches are relative to the nvme-4.19 branch.

Johannes Thumshirn (1):
nvme: trace: add disk name to tracepoints

Sagi Grimberg (1):
nvme: cache struct nvme_ctrl reference to struct nvme_request

drivers/nvme/host/core.c | 10 ++++++----
drivers/nvme/host/fc.c | 2 +-
drivers/nvme/host/nvme.h | 5 +++--
drivers/nvme/host/pci.c | 2 +-
drivers/nvme/host/rdma.c | 2 +-
drivers/nvme/host/trace.h | 30 +++++++++++++++++++-----------
drivers/nvme/target/loop.c | 2 +-
7 files changed, 32 insertions(+), 21 deletions(-)

--
2.16.4



2018-06-26 14:25:33

by Johannes Thumshirn

[permalink] [raw]
Subject: [PATCH v4 1/2] nvme: cache struct nvme_ctrl reference to struct nvme_request

From: Sagi Grimberg <[email protected]>

We will need to reference the controller in the setup and completion
time for tracing and future traffic based keep alive support.

Signed-off-by: Sagi Grimberg <[email protected]>
---
drivers/nvme/host/core.c | 6 ++++--
drivers/nvme/host/fc.c | 2 +-
drivers/nvme/host/nvme.h | 5 +++--
drivers/nvme/host/pci.c | 2 +-
drivers/nvme/host/rdma.c | 2 +-
drivers/nvme/target/loop.c | 2 +-
6 files changed, 11 insertions(+), 8 deletions(-)

diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index e541fe268bcf..62602af9eb77 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -390,6 +390,7 @@ static inline void nvme_clear_nvme_request(struct request *req)
if (!(req->rq_flags & RQF_DONTPREP)) {
nvme_req(req)->retries = 0;
nvme_req(req)->flags = 0;
+ nvme_req(req)->ctrl = NULL;
req->rq_flags |= RQF_DONTPREP;
}
}
@@ -622,8 +623,8 @@ static inline blk_status_t nvme_setup_rw(struct nvme_ns *ns,
return 0;
}

-blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
- struct nvme_command *cmd)
+blk_status_t nvme_setup_cmd(struct nvme_ctrl *ctrl, struct nvme_ns *ns,
+ struct request *req, struct nvme_command *cmd)
{
blk_status_t ret = BLK_STS_OK;

@@ -652,6 +653,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
}

cmd->common.command_id = req->tag;
+ nvme_req(req)->ctrl = ctrl;
if (ns)
trace_nvme_setup_nvm_cmd(req->q->id, cmd);
else
diff --git a/drivers/nvme/host/fc.c b/drivers/nvme/host/fc.c
index 41d45a1b5c62..afde86f3ac6e 100644
--- a/drivers/nvme/host/fc.c
+++ b/drivers/nvme/host/fc.c
@@ -2274,7 +2274,7 @@ nvme_fc_queue_rq(struct blk_mq_hw_ctx *hctx,
!nvmf_check_ready(&queue->ctrl->ctrl, rq, queue_ready))
return nvmf_fail_nonready_command(rq);

- ret = nvme_setup_cmd(ns, rq, sqe);
+ ret = nvme_setup_cmd(&ctrl->ctrl, ns, rq, sqe);
if (ret)
return ret;

diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index 0c4a33df3b2f..6fb9dcec6d93 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -102,6 +102,7 @@ struct nvme_request {
u8 retries;
u8 flags;
u16 status;
+ struct nvme_ctrl *ctrl;
};

/*
@@ -420,8 +421,8 @@ void nvme_start_freeze(struct nvme_ctrl *ctrl);
#define NVME_QID_ANY -1
struct request *nvme_alloc_request(struct request_queue *q,
struct nvme_command *cmd, blk_mq_req_flags_t flags, int qid);
-blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
- struct nvme_command *cmd);
+blk_status_t nvme_setup_cmd(struct nvme_ctrl *ctrl, struct nvme_ns *ns,
+ struct request *req, struct nvme_command *cmd);
int nvme_submit_sync_cmd(struct request_queue *q, struct nvme_command *cmd,
void *buf, unsigned bufflen);
int __nvme_submit_sync_cmd(struct request_queue *q, struct nvme_command *cmd,
diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
index ba943f211687..a3750205da69 100644
--- a/drivers/nvme/host/pci.c
+++ b/drivers/nvme/host/pci.c
@@ -883,7 +883,7 @@ static blk_status_t nvme_queue_rq(struct blk_mq_hw_ctx *hctx,
if (unlikely(nvmeq->cq_vector < 0))
return BLK_STS_IOERR;

- ret = nvme_setup_cmd(ns, req, &cmnd);
+ ret = nvme_setup_cmd(&dev->ctrl, ns, req, &cmnd);
if (ret)
return ret;

diff --git a/drivers/nvme/host/rdma.c b/drivers/nvme/host/rdma.c
index 9f5fc7b7fd7f..fefa661f89a0 100644
--- a/drivers/nvme/host/rdma.c
+++ b/drivers/nvme/host/rdma.c
@@ -1685,7 +1685,7 @@ static blk_status_t nvme_rdma_queue_rq(struct blk_mq_hw_ctx *hctx,
ib_dma_sync_single_for_cpu(dev, sqe->dma,
sizeof(struct nvme_command), DMA_TO_DEVICE);

- ret = nvme_setup_cmd(ns, rq, c);
+ ret = nvme_setup_cmd(&queue->ctrl->ctrl, ns, rq, c);
if (ret)
return ret;

diff --git a/drivers/nvme/target/loop.c b/drivers/nvme/target/loop.c
index d8d91f04bd7e..888bd3fefc4d 100644
--- a/drivers/nvme/target/loop.c
+++ b/drivers/nvme/target/loop.c
@@ -164,7 +164,7 @@ static blk_status_t nvme_loop_queue_rq(struct blk_mq_hw_ctx *hctx,
if (!nvmf_check_ready(&queue->ctrl->ctrl, req, queue_ready))
return nvmf_fail_nonready_command(req);

- ret = nvme_setup_cmd(ns, req, &iod->cmd);
+ ret = nvme_setup_cmd(&queue->ctrl->ctrl, ns, req, &iod->cmd);
if (ret)
return ret;

--
2.16.4


2018-06-26 16:00:56

by Johannes Thumshirn

[permalink] [raw]
Subject: [PATCH] nvme: trace: add disk name to tracepoints

Add disk name to tracepoints so we can better distinguish between
individual disks in the trace output and admin commands which
are represented without a disk name.

Signed-off-by: Johannes Thumshirn <[email protected]>
---
drivers/nvme/host/core.c | 4 ++--
drivers/nvme/host/trace.h | 39 +++++++++++++++++++++++++--------------
2 files changed, 27 insertions(+), 16 deletions(-)

diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 62602af9eb77..cc1340948245 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -655,9 +655,9 @@ blk_status_t nvme_setup_cmd(struct nvme_ctrl *ctrl, struct nvme_ns *ns,
cmd->common.command_id = req->tag;
nvme_req(req)->ctrl = ctrl;
if (ns)
- trace_nvme_setup_nvm_cmd(req->q->id, cmd);
+ trace_nvme_setup_nvm_cmd(req, cmd, ns->disk->disk_name);
else
- trace_nvme_setup_admin_cmd(cmd);
+ trace_nvme_setup_admin_cmd(req, cmd);
return ret;
}
EXPORT_SYMBOL_GPL(nvme_setup_cmd);
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 01390f0e1671..371a816cd225 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -76,9 +76,10 @@ const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
nvme_trace_parse_nvm_cmd(p, opcode, cdw10)

TRACE_EVENT(nvme_setup_admin_cmd,
- TP_PROTO(struct nvme_command *cmd),
- TP_ARGS(cmd),
+ TP_PROTO(struct request *req, struct nvme_command *cmd),
+ TP_ARGS(req, cmd),
TP_STRUCT__entry(
+ __field(int, ctrl_id)
__field(u8, opcode)
__field(u8, flags)
__field(u16, cid)
@@ -86,6 +87,7 @@ TRACE_EVENT(nvme_setup_admin_cmd,
__array(u8, cdw10, 24)
),
TP_fast_assign(
+ __entry->ctrl_id = nvme_req(req)->ctrl->cntlid;
__entry->opcode = cmd->common.opcode;
__entry->flags = cmd->common.flags;
__entry->cid = cmd->common.command_id;
@@ -93,17 +95,21 @@ TRACE_EVENT(nvme_setup_admin_cmd,
memcpy(__entry->cdw10, cmd->common.cdw10,
sizeof(__entry->cdw10));
),
- TP_printk(" cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
- __entry->cid, __entry->flags, __entry->metadata,
+ TP_printk("nvme%d: cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
+ __entry->ctrl_id, __entry->cid, __entry->flags,
+ __entry->metadata,
show_admin_opcode_name(__entry->opcode),
__parse_nvme_admin_cmd(__entry->opcode, __entry->cdw10))
);


TRACE_EVENT(nvme_setup_nvm_cmd,
- TP_PROTO(int qid, struct nvme_command *cmd),
- TP_ARGS(qid, cmd),
+ TP_PROTO(struct request *req, struct nvme_command *cmd,
+ char *disk_name),
+ TP_ARGS(req, cmd, disk_name),
TP_STRUCT__entry(
+ __string(name, disk_name)
+ __field(int, ctrl_id)
__field(int, qid)
__field(u8, opcode)
__field(u8, flags)
@@ -113,7 +119,9 @@ TRACE_EVENT(nvme_setup_nvm_cmd,
__array(u8, cdw10, 24)
),
TP_fast_assign(
- __entry->qid = qid;
+ __assign_str(name, disk_name);
+ __entry->ctrl_id = nvme_req(req)->ctrl->cntlid;
+ __entry->qid = req->q->id;
__entry->opcode = cmd->common.opcode;
__entry->flags = cmd->common.flags;
__entry->cid = cmd->common.command_id;
@@ -122,10 +130,10 @@ TRACE_EVENT(nvme_setup_nvm_cmd,
memcpy(__entry->cdw10, cmd->common.cdw10,
sizeof(__entry->cdw10));
),
- TP_printk("qid=%d, nsid=%u, cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
- __entry->qid, __entry->nsid, __entry->cid,
- __entry->flags, __entry->metadata,
- show_opcode_name(__entry->opcode),
+ TP_printk("nvme%d: disk=%s, qid=%d, nsid=%u, cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
+ __entry->ctrl_id, __get_str(name), __entry->qid,
+ __entry->nsid, __entry->cid, __entry->flags,
+ __entry->metadata, show_opcode_name(__entry->opcode),
__parse_nvme_cmd(__entry->opcode, __entry->cdw10))
);

@@ -133,6 +141,7 @@ TRACE_EVENT(nvme_complete_rq,
TP_PROTO(struct request *req),
TP_ARGS(req),
TP_STRUCT__entry(
+ __field(int, ctrl_id)
__field(int, qid)
__field(int, cid)
__field(u64, result)
@@ -141,6 +150,7 @@ TRACE_EVENT(nvme_complete_rq,
__field(u16, status)
),
TP_fast_assign(
+ __entry->ctrl_id = nvme_req(req)->ctrl->cntlid;
__entry->qid = req->q->id;
__entry->cid = req->tag;
__entry->result = le64_to_cpu(nvme_req(req)->result.u64);
@@ -148,9 +158,10 @@ TRACE_EVENT(nvme_complete_rq,
__entry->flags = nvme_req(req)->flags;
__entry->status = nvme_req(req)->status;
),
- TP_printk("qid=%d, cmdid=%u, res=%llu, retries=%u, flags=0x%x, status=%u",
- __entry->qid, __entry->cid, __entry->result,
- __entry->retries, __entry->flags, __entry->status)
+ TP_printk("nvme%d: qid=%d, cmdid=%u, res=%llu, retries=%u, flags=0x%x, status=%u",
+ __entry->ctrl_id, __entry->qid, __entry->cid,
+ __entry->result, __entry->retries, __entry->flags,
+ __entry->status)

);

--
2.16.4


2018-06-26 16:06:02

by Keith Busch

[permalink] [raw]
Subject: Re: [PATCH v4 1/2] nvme: cache struct nvme_ctrl reference to struct nvme_request

On Tue, Jun 26, 2018 at 03:51:40PM +0200, Johannes Thumshirn wrote:
> @@ -652,6 +653,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
> }
>
> cmd->common.command_id = req->tag;
> + nvme_req(req)->ctrl = ctrl;
> if (ns)
> trace_nvme_setup_nvm_cmd(req->q->id, cmd);
> else

I don't think we need to do this per-io. The request coming from the
controller's tagset, so we can do this just once at .init_request time,
right?

2018-06-26 16:06:54

by Keith Busch

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Tue, Jun 26, 2018 at 03:51:41PM +0200, Johannes Thumshirn wrote:
> @@ -655,9 +655,9 @@ blk_status_t nvme_setup_cmd(struct nvme_ctrl *ctrl, struct nvme_ns *ns,
> cmd->common.command_id = req->tag;
> nvme_req(req)->ctrl = ctrl;
> if (ns)
> - trace_nvme_setup_nvm_cmd(req->q->id, cmd);
> + trace_nvme_setup_nvm_cmd(req, cmd, ns->disk->disk_name);

Not related to your patch, but I did notice that the req->q->id isn't
really useful here since that's not the hardware context identifier.
That's just some ida assigned software identifier. For the admin command
completion trace, it's actually a little confusing to see the qid in the
trace.

2018-06-27 07:41:29

by Johannes Thumshirn

[permalink] [raw]
Subject: Re: [PATCH v4 1/2] nvme: cache struct nvme_ctrl reference to struct nvme_request

On Tue, Jun 26, 2018 at 08:55:32AM -0600, Keith Busch wrote:
> On Tue, Jun 26, 2018 at 03:51:40PM +0200, Johannes Thumshirn wrote:
> > @@ -652,6 +653,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
> > }
> >
> > cmd->common.command_id = req->tag;
> > + nvme_req(req)->ctrl = ctrl;
> > if (ns)
> > trace_nvme_setup_nvm_cmd(req->q->id, cmd);
> > else
>
> I don't think we need to do this per-io. The request coming from the
> controller's tagset, so we can do this just once at .init_request time,
> right?

Agreed, but as it's Sagi's patch I'd like to hear his opinion on this
before changing it.

Byte,
Johannes
--
Johannes Thumshirn Storage
[email protected] +49 911 74053 689
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 N?rnberg
GF: Felix Imend?rffer, Jane Smithard, Graham Norton
HRB 21284 (AG N?rnberg)
Key fingerprint = EC38 9CAB C2C4 F25D 8600 D0D0 0393 969D 2D76 0850

2018-06-27 08:07:53

by Sagi Grimberg

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints


>> Not related to your patch, but I did notice that the req->q->id isn't
>> really useful here since that's not the hardware context identifier.
>> That's just some ida assigned software identifier. For the admin command
>> completion trace, it's actually a little confusing to see the qid in the
>> trace.
>
> It was actually requested by Martin so we can easily see which request
> got dispatched/completed on which request queue.

Would be good in the future to display the hwqid, but we'll need to work
before we can do that.

Maybe change the display to request_queue_id=%d?

2018-06-27 08:47:54

by Sagi Grimberg

[permalink] [raw]
Subject: Re: [PATCH v4 1/2] nvme: cache struct nvme_ctrl reference to struct nvme_request


>>> @@ -652,6 +653,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
>>> }
>>>
>>> cmd->common.command_id = req->tag;
>>> + nvme_req(req)->ctrl = ctrl;
>>> if (ns)
>>> trace_nvme_setup_nvm_cmd(req->q->id, cmd);
>>> else
>>
>> I don't think we need to do this per-io. The request coming from the
>> controller's tagset, so we can do this just once at .init_request time,
>> right?
>
> Agreed, but as it's Sagi's patch I'd like to hear his opinion on this
> before changing it.

That's a good idea!

seems to work... Johannes, can you respin with this version?
Please CC james and keith on it too.
--
nvme: cache struct nvme_ctrl reference to struct nvme_request

We will need to reference the controller in the setup and
completion time for tracing and future traffic based keep alive
support.

Signed-off-by: Sagi Grimberg <[email protected]>

diff --git a/drivers/nvme/host/fc.c b/drivers/nvme/host/fc.c
index 41d45a1b5c62..9cc33752539a 100644
--- a/drivers/nvme/host/fc.c
+++ b/drivers/nvme/host/fc.c
@@ -1737,6 +1737,7 @@ nvme_fc_init_request(struct blk_mq_tag_set *set,
struct request *rq,
int queue_idx = (set == &ctrl->tag_set) ? hctx_idx + 1 : 0;
struct nvme_fc_queue *queue = &ctrl->queues[queue_idx];

+ nvme_req(rq)->ctrl = &ctrl->ctrl;
return __nvme_fc_init_request(ctrl, queue, op, rq, queue->rqcnt++);
}

diff --git a/drivers/nvme/host/nvme.h b/drivers/nvme/host/nvme.h
index 0c4a33df3b2f..f2249387b60d 100644
--- a/drivers/nvme/host/nvme.h
+++ b/drivers/nvme/host/nvme.h
@@ -102,6 +102,7 @@ struct nvme_request {
u8 retries;
u8 flags;
u16 status;
+ struct nvme_ctrl *ctrl;
};

/*
diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
index ba943f211687..d2bd60d8315a 100644
--- a/drivers/nvme/host/pci.c
+++ b/drivers/nvme/host/pci.c
@@ -418,6 +418,7 @@ static int nvme_init_request(struct blk_mq_tag_set
*set, struct request *req,

BUG_ON(!nvmeq);
iod->nvmeq = nvmeq;
+ nvme_req(req)->ctrl = &dev->ctrl;
return 0;
}

diff --git a/drivers/nvme/host/rdma.c b/drivers/nvme/host/rdma.c
index 20db67d53ffa..e4087caf8754 100644
--- a/drivers/nvme/host/rdma.c
+++ b/drivers/nvme/host/rdma.c
@@ -292,6 +292,7 @@ static int nvme_rdma_init_request(struct
blk_mq_tag_set *set,
return ret;

req->queue = queue;
+ nvme_req(rq)->ctrl = &ctrl->ctrl;

return 0;
}
diff --git a/drivers/nvme/target/loop.c b/drivers/nvme/target/loop.c
index d8d91f04bd7e..af7fbf4132b0 100644
--- a/drivers/nvme/target/loop.c
+++ b/drivers/nvme/target/loop.c
@@ -227,6 +227,7 @@ static int nvme_loop_init_request(struct
blk_mq_tag_set *set,
{
struct nvme_loop_ctrl *ctrl = set->driver_data;

+ nvme_req(req)->ctrl = &ctrl->ctrl;
return nvme_loop_init_iod(ctrl, blk_mq_rq_to_pdu(req),
(set == &ctrl->tag_set) ? hctx_idx + 1 : 0);
}
--

2018-06-27 09:22:58

by Johannes Thumshirn

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Tue, Jun 26, 2018 at 09:01:06AM -0600, Keith Busch wrote:
> Not related to your patch, but I did notice that the req->q->id isn't
> really useful here since that's not the hardware context identifier.
> That's just some ida assigned software identifier. For the admin command
> completion trace, it's actually a little confusing to see the qid in the
> trace.

It was actually requested by Martin so we can easily see which request
got dispatched/completed on which request queue.

--
Johannes Thumshirn Storage
[email protected] +49 911 74053 689
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 N?rnberg
GF: Felix Imend?rffer, Jane Smithard, Graham Norton
HRB 21284 (AG N?rnberg)
Key fingerprint = EC38 9CAB C2C4 F25D 8600 D0D0 0393 969D 2D76 0850

2018-06-27 10:15:21

by Johannes Thumshirn

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Wed, Jun 27, 2018 at 11:06:22AM +0300, Sagi Grimberg wrote:
> Maybe change the display to request_queue_id=%d?

request_queue_id is pretty long, how about rqid?

--
Johannes Thumshirn Storage
[email protected] +49 911 74053 689
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 N?rnberg
GF: Felix Imend?rffer, Jane Smithard, Graham Norton
HRB 21284 (AG N?rnberg)
Key fingerprint = EC38 9CAB C2C4 F25D 8600 D0D0 0393 969D 2D76 0850

2018-06-27 23:57:21

by Keith Busch

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Wed, Jun 27, 2018 at 11:06:22AM +0300, Sagi Grimberg wrote:
>
> > > Not related to your patch, but I did notice that the req->q->id isn't
> > > really useful here since that's not the hardware context identifier.
> > > That's just some ida assigned software identifier. For the admin command
> > > completion trace, it's actually a little confusing to see the qid in the
> > > trace.
> >
> > It was actually requested by Martin so we can easily see which request
> > got dispatched/completed on which request queue.
>
> Would be good in the future to display the hwqid, but we'll need to work
> before we can do that.

I'd really like to see nvme qid, and it would allow for nice trace
filters. We could use a little help from blk-mq to get the hctx's
queue_num from a struct request. I think following should get us that
(haven't tested just yet)

---
diff --git a/block/blk-mq.c b/block/blk-mq.c
index b429d515b568..c6478833464d 100644
--- a/block/blk-mq.c
+++ b/block/blk-mq.c
@@ -466,6 +466,12 @@ struct request *blk_mq_alloc_request_hctx(struct request_queue *q,
}
EXPORT_SYMBOL_GPL(blk_mq_alloc_request_hctx);

+unsigned int blk_mq_request_hctx_idx(struct request *rq)
+{
+ return blk_mq_map_queue(rq->q, rq->mq_ctx->cpu)->queue_num;
+}
+EXPORT_SYMBOL_GPL(blk_mq_request_hctx_idx);
+
static void __blk_mq_free_request(struct request *rq)
{
struct request_queue *q = rq->q;
diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 46df030b2c3f..6a30c154aa99 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -653,7 +653,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,

cmd->common.command_id = req->tag;
if (ns)
- trace_nvme_setup_nvm_cmd(req->q->id, cmd);
+ trace_nvme_setup_nvm_cmd(req, cmd);
else
trace_nvme_setup_admin_cmd(cmd);
return ret;
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 01390f0e1671..95ebe803424b 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -79,6 +79,7 @@ TRACE_EVENT(nvme_setup_admin_cmd,
TP_PROTO(struct nvme_command *cmd),
TP_ARGS(cmd),
TP_STRUCT__entry(
+ __field(int, qid)
__field(u8, opcode)
__field(u8, flags)
__field(u16, cid)
@@ -86,6 +87,7 @@ TRACE_EVENT(nvme_setup_admin_cmd,
__array(u8, cdw10, 24)
),
TP_fast_assign(
+ __entry->qid = 0;
__entry->opcode = cmd->common.opcode;
__entry->flags = cmd->common.flags;
__entry->cid = cmd->common.command_id;
@@ -93,16 +95,16 @@ TRACE_EVENT(nvme_setup_admin_cmd,
memcpy(__entry->cdw10, cmd->common.cdw10,
sizeof(__entry->cdw10));
),
- TP_printk(" cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
- __entry->cid, __entry->flags, __entry->metadata,
+ TP_printk("qid=%d, cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
+ __entry->qid, __entry->cid, __entry->flags, __entry->metadata,
show_admin_opcode_name(__entry->opcode),
__parse_nvme_admin_cmd(__entry->opcode, __entry->cdw10))
);


TRACE_EVENT(nvme_setup_nvm_cmd,
- TP_PROTO(int qid, struct nvme_command *cmd),
- TP_ARGS(qid, cmd),
+ TP_PROTO(struct request *req, struct nvme_command *cmd),
+ TP_ARGS(req, cmd),
TP_STRUCT__entry(
__field(int, qid)
__field(u8, opcode)
@@ -113,7 +115,7 @@ TRACE_EVENT(nvme_setup_nvm_cmd,
__array(u8, cdw10, 24)
),
TP_fast_assign(
- __entry->qid = qid;
+ __entry->qid = blk_mq_request_hctx_idx(req) + !!req->rq_disk;
__entry->opcode = cmd->common.opcode;
__entry->flags = cmd->common.flags;
__entry->cid = cmd->common.command_id;
@@ -141,7 +143,7 @@ TRACE_EVENT(nvme_complete_rq,
__field(u16, status)
),
TP_fast_assign(
- __entry->qid = req->q->id;
+ __entry->qid = blk_mq_request_hctx_idx(req) + !!req->rq_disk;
__entry->cid = req->tag;
__entry->result = le64_to_cpu(nvme_req(req)->result.u64);
__entry->retries = nvme_req(req)->retries;
diff --git a/include/linux/blk-mq.h b/include/linux/blk-mq.h
index e3147eb74222..af91b2d31a04 100644
--- a/include/linux/blk-mq.h
+++ b/include/linux/blk-mq.h
@@ -248,6 +248,7 @@ static inline u16 blk_mq_unique_tag_to_tag(u32 unique_tag)
}


+unsigned int blk_mq_request_hctx_idx(struct request *rq);
int blk_mq_request_started(struct request *rq);
void blk_mq_start_request(struct request *rq);
void blk_mq_end_request(struct request *rq, blk_status_t error);
--

2018-06-28 01:15:49

by Keith Busch

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

Thinking more on this, not using the hw qid really limits the utility
out of using these trace events: We may not be able to match a completion
to the submission without it since cmdid alone isn't enough to match up
the two events.

Here's an updated proposal and actually tested. I was also able to
combine admin and io submissions.

---
diff --git a/block/blk-mq.c b/block/blk-mq.c
index b429d51..c647883 100644
--- a/block/blk-mq.c
+++ b/block/blk-mq.c
@@ -466,6 +466,12 @@ struct request *blk_mq_alloc_request_hctx(struct request_queue *q,
}
EXPORT_SYMBOL_GPL(blk_mq_alloc_request_hctx);

+unsigned int blk_mq_request_hctx_idx(struct request *rq)
+{
+ return blk_mq_map_queue(rq->q, rq->mq_ctx->cpu)->queue_num;
+}
+EXPORT_SYMBOL_GPL(blk_mq_request_hctx_idx);
+
static void __blk_mq_free_request(struct request *rq)
{
struct request_queue *q = rq->q;
diff --git a/drivers/nvme/host/core.c b/drivers/nvme/host/core.c
index 46df030..f46bde2 100644
--- a/drivers/nvme/host/core.c
+++ b/drivers/nvme/host/core.c
@@ -652,10 +654,7 @@ blk_status_t nvme_setup_cmd(struct nvme_ns *ns, struct request *req,
}

cmd->common.command_id = req->tag;
- if (ns)
- trace_nvme_setup_nvm_cmd(req->q->id, cmd);
- else
- trace_nvme_setup_admin_cmd(cmd);
+ trace_nvme_setup_nvm_cmd(req, cmd);
return ret;
}
EXPORT_SYMBOL_GPL(nvme_setup_cmd);
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 01390f0..bca3451 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -75,34 +75,9 @@ const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
#define __parse_nvme_cmd(opcode, cdw10) \
nvme_trace_parse_nvm_cmd(p, opcode, cdw10)

-TRACE_EVENT(nvme_setup_admin_cmd,
- TP_PROTO(struct nvme_command *cmd),
- TP_ARGS(cmd),
- TP_STRUCT__entry(
- __field(u8, opcode)
- __field(u8, flags)
- __field(u16, cid)
- __field(u64, metadata)
- __array(u8, cdw10, 24)
- ),
- TP_fast_assign(
- __entry->opcode = cmd->common.opcode;
- __entry->flags = cmd->common.flags;
- __entry->cid = cmd->common.command_id;
- __entry->metadata = le64_to_cpu(cmd->common.metadata);
- memcpy(__entry->cdw10, cmd->common.cdw10,
- sizeof(__entry->cdw10));
- ),
- TP_printk(" cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
- __entry->cid, __entry->flags, __entry->metadata,
- show_admin_opcode_name(__entry->opcode),
- __parse_nvme_admin_cmd(__entry->opcode, __entry->cdw10))
-);
-
-
TRACE_EVENT(nvme_setup_nvm_cmd,
- TP_PROTO(int qid, struct nvme_command *cmd),
- TP_ARGS(qid, cmd),
+ TP_PROTO(struct request *req, struct nvme_command *cmd),
+ TP_ARGS(req, cmd),
TP_STRUCT__entry(
__field(int, qid)
__field(u8, opcode)
@@ -113,7 +88,7 @@ TRACE_EVENT(nvme_setup_nvm_cmd,
__array(u8, cdw10, 24)
),
TP_fast_assign(
- __entry->qid = qid;
+ __entry->qid = blk_mq_request_hctx_idx(req) + !!req->rq_disk;
__entry->opcode = cmd->common.opcode;
__entry->flags = cmd->common.flags;
__entry->cid = cmd->common.command_id;
@@ -125,8 +100,12 @@ TRACE_EVENT(nvme_setup_nvm_cmd,
TP_printk("qid=%d, nsid=%u, cmdid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
__entry->qid, __entry->nsid, __entry->cid,
__entry->flags, __entry->metadata,
- show_opcode_name(__entry->opcode),
- __parse_nvme_cmd(__entry->opcode, __entry->cdw10))
+ __entry->qid ?
+ show_opcode_name(__entry->opcode) :
+ show_admin_opcode_name(__entry->opcode),
+ __entry->qid ?
+ __parse_nvme_cmd(__entry->opcode, __entry->cdw10) :
+ __parse_nvme_admin_cmd(__entry->opcode, __entry->cdw10))
);

TRACE_EVENT(nvme_complete_rq,
@@ -141,7 +120,7 @@ TRACE_EVENT(nvme_complete_rq,
__field(u16, status)
),
TP_fast_assign(
- __entry->qid = req->q->id;
+ __entry->qid = blk_mq_request_hctx_idx(req) + !!req->rq_disk;
__entry->cid = req->tag;
__entry->result = le64_to_cpu(nvme_req(req)->result.u64);
__entry->retries = nvme_req(req)->retries;
diff --git a/include/linux/blk-mq.h b/include/linux/blk-mq.h
index e3147eb..af91b2d 100644
--- a/include/linux/blk-mq.h
+++ b/include/linux/blk-mq.h
@@ -248,6 +248,7 @@ static inline u16 blk_mq_unique_tag_to_tag(u32 unique_tag)
}


+unsigned int blk_mq_request_hctx_idx(struct request *rq);
int blk_mq_request_started(struct request *rq);
void blk_mq_start_request(struct request *rq);
void blk_mq_end_request(struct request *rq, blk_status_t error);
--

2018-06-28 14:35:31

by Sagi Grimberg

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints


> Thinking more on this, not using the hw qid really limits the utility
> out of using these trace events: We may not be able to match a completion
> to the submission without it since cmdid alone isn't enough to match up
> the two events.
>
> Here's an updated proposal and actually tested. I was also able to
> combine admin and io submissions.

This looks good!

One thing that is missing is the controller id when we have multiple
controllers/subsystems in the host like:

TP_printk("nvme%d: qid=%d, nsid=%u, cmdid=%u, flags=0x%x, meta=0x%llx,
cmd=(%s %s)",

But Johannes can add it I guess.


2018-06-28 20:28:07

by Johannes Thumshirn

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Wed, Jun 27, 2018 at 06:59:43PM -0600, Keith Busch wrote:
> Thinking more on this, not using the hw qid really limits the utility
> out of using these trace events: We may not be able to match a completion
> to the submission without it since cmdid alone isn't enough to match up
> the two events.
>
> Here's an updated proposal and actually tested. I was also able to
> combine admin and io submissions.

Awesome, thanks.

Reviewed-by: Johannes Thumshirn <[email protected]>
--
Johannes Thumshirn Storage
[email protected] +49 911 74053 689
SUSE LINUX GmbH, Maxfeldstr. 5, 90409 N?rnberg
GF: Felix Imend?rffer, Jane Smithard, Graham Norton
HRB 21284 (AG N?rnberg)
Key fingerprint = EC38 9CAB C2C4 F25D 8600 D0D0 0393 969D 2D76 0850

2018-06-28 22:27:14

by Keith Busch

[permalink] [raw]
Subject: Re: [PATCH] nvme: trace: add disk name to tracepoints

On Thu, Jun 28, 2018 at 05:34:07PM +0300, Sagi Grimberg wrote:
>
> > Thinking more on this, not using the hw qid really limits the utility
> > out of using these trace events: We may not be able to match a completion
> > to the submission without it since cmdid alone isn't enough to match up
> > the two events.
> >
> > Here's an updated proposal and actually tested. I was also able to
> > combine admin and io submissions.
>
> This looks good!
>
> One thing that is missing is the controller id when we have multiple
> controllers/subsystems in the host like:
>
> TP_printk("nvme%d: qid=%d, nsid=%u, cmdid=%u, flags=0x%x, meta=0x%llx,
> cmd=(%s %s)",
>
> But Johannes can add it I guess.

Yep, I'm sort of going off on a tangent from what Johannes was adding.
We definitely need both. I have some time today, I'll send out the a
series with the combined results.