Export bellow three functions:
nvme_trace_parse_admin_cmd
nvme_trace_parse_nvm_cmd
nvme_trace_disk_name
Thus any other modules which depends on nvme-core could use the trace
events in trace.h
Signed-off-by: yupeng <[email protected]>
---
drivers/nvme/host/trace.c | 3 +++
1 file changed, 3 insertions(+)
diff --git a/drivers/nvme/host/trace.c b/drivers/nvme/host/trace.c
index 25b0e310f4a8..8ca7079ed2bc 100644
--- a/drivers/nvme/host/trace.c
+++ b/drivers/nvme/host/trace.c
@@ -113,6 +113,7 @@ const char *nvme_trace_parse_admin_cmd(struct trace_seq *p,
return nvme_trace_common(p, cdw10);
}
}
+EXPORT_SYMBOL_GPL(nvme_trace_parse_admin_cmd);
const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p,
u8 opcode, u8 *cdw10)
@@ -128,6 +129,7 @@ const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p,
return nvme_trace_common(p, cdw10);
}
}
+EXPORT_SYMBOL_GPL(nvme_trace_parse_nvm_cmd);
const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
{
@@ -139,3 +141,4 @@ const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
return ret;
}
+EXPORT_SYMBOL_GPL(nvme_trace_disk_name);
--
2.17.1
export nvme disk name, queue id, sq_head, sq_tail to trace event
usage example:
go to the event directory:
cd /sys/kernel/debug/tracing/events/nvme/nvme_sq
filter by disk name:
echo 'disk=="nvme1n1"' > filter
enable the event:
echo 1 > enable
check results from trace_pipe:
cat /sys/kernel/debug/tracing/trace_pipe
In practice, this patch help me debug hardware related
performant issue.
Signed-off-by: yupeng <[email protected]>
---
drivers/nvme/host/pci.c | 5 +++++
drivers/nvme/host/trace.c | 2 ++
drivers/nvme/host/trace.h | 21 +++++++++++++++++++++
3 files changed, 28 insertions(+)
diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
index c33bb201b884..52df2f7fef37 100644
--- a/drivers/nvme/host/pci.c
+++ b/drivers/nvme/host/pci.c
@@ -32,6 +32,7 @@
#include <linux/sed-opal.h>
#include <linux/pci-p2pdma.h>
+#include "trace.h"
#include "nvme.h"
#define SQ_SIZE(depth) (depth * sizeof(struct nvme_command))
@@ -899,6 +900,10 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
}
req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
+ trace_nvme_sq(req->rq_disk,
+ nvmeq->qid,
+ le16_to_cpu(cqe->sq_head),
+ nvmeq->sq_tail);
nvme_end_request(req, cqe->status, cqe->result);
}
diff --git a/drivers/nvme/host/trace.c b/drivers/nvme/host/trace.c
index 8ca7079ed2bc..7bfaace23e1e 100644
--- a/drivers/nvme/host/trace.c
+++ b/drivers/nvme/host/trace.c
@@ -142,3 +142,5 @@ const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
return ret;
}
EXPORT_SYMBOL_GPL(nvme_trace_disk_name);
+
+EXPORT_TRACEPOINT_SYMBOL(nvme_sq);
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 196d5bd56718..3606cd7000f4 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -184,6 +184,27 @@ TRACE_EVENT(nvme_async_event,
#undef aer_name
+TRACE_EVENT(nvme_sq,
+ TP_PROTO(void *rq_disk, int qid, int sq_head, int sq_tail),
+ TP_ARGS(rq_disk, qid, sq_head, sq_tail),
+ TP_STRUCT__entry(
+ __array(char, disk, DISK_NAME_LEN)
+ __field(int, qid)
+ __field(int, sq_head)
+ __field(int, sq_tail)
+ ),
+ TP_fast_assign(
+ __assign_disk_name(__entry->disk, rq_disk);
+ __entry->qid = qid;
+ __entry->sq_head = sq_head;
+ __entry->sq_tail = sq_tail;
+ ),
+ TP_printk("nvme: %s qid=%d head=%d tail=%d",
+ __print_disk_name(__entry->disk),
+ __entry->qid, __entry->sq_head, __entry->sq_tail
+ )
+);
+
#endif /* _TRACE_NVME_H */
#undef TRACE_INCLUDE_PATH
--
2.17.1
> @@ -899,6 +900,10 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
> }
>
> req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
> + trace_nvme_sq(req->rq_disk,
> + nvmeq->qid,
> + le16_to_cpu(cqe->sq_head),
> + nvmeq->sq_tail);
Why the newline escapes? why not escape at the 80 char border?
Other than that, looks fine,
Reviewed-by: Sagi Grimberg <[email protected]>
Reviewed-by: Sagi Grimberg <[email protected]>
On Mon, Dec 17, 2018 at 11:26 PM Sagi Grimberg <[email protected]> wrote:
>
>
> > @@ -899,6 +900,10 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
> > }
> >
> > req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
> > + trace_nvme_sq(req->rq_disk,
> > + nvmeq->qid,
> > + le16_to_cpu(cqe->sq_head),
> > + nvmeq->sq_tail);
>
> Why the newline escapes? why not escape at the 80 char border?
>
Sorry, I don't quite understand your meaning. Do you mean I'd better
change this:
trace_nvme_sq(req->rq_disk,
nvmeq->qid,
le16_to_cpu(cqe->sq_head),
nvmeq->sq_tail);
to something like below:
trace_nvme_sq(req->rq_disk, nvmeq->qid, le16_to_cpu(cqe->sq_head),
nvmeq->sq_tail);
Please let me know whether my understanding is correct.
On Mon, Dec 17, 2018 at 08:51:37PM -0800, yupeng wrote:
> Export bellow three functions:
> nvme_trace_parse_admin_cmd
> nvme_trace_parse_nvm_cmd
> nvme_trace_disk_name
> Thus any other modules which depends on nvme-core could use the trace
> events in trace.h
But we don't actually use these trace events anywhere outside of core.c,
even with your second patch, do we?
On Tue, Dec 18, 2018 at 05:57:06PM +0100, Christoph Hellwig wrote:
>
>
> On Mon, Dec 17, 2018 at 08:51:37PM -0800, yupeng wrote:
> > Export bellow three functions:
> > nvme_trace_parse_admin_cmd
> > nvme_trace_parse_nvm_cmd
> > nvme_trace_disk_name
> > Thus any other modules which depends on nvme-core could use the trace
> > events in trace.h
>
> But we don't actually use these trace events anywhere outside of core.c,
> even with your second patch, do we?
Except for nvme_trace_disk_name, which is used via __print_disk_name.
On Mon, Dec 17, 2018 at 11:44:51PM -0800, peng yu wrote:
> Sorry, I don't quite understand your meaning. Do you mean I'd better
> change this:
> trace_nvme_sq(req->rq_disk,
> nvmeq->qid,
> le16_to_cpu(cqe->sq_head),
> nvmeq->sq_tail);
> to something like below:
> trace_nvme_sq(req->rq_disk, nvmeq->qid, le16_to_cpu(cqe->sq_head),
> nvmeq->sq_tail);
> Please let me know whether my understanding is correct.
Yes. Let me know if this version that I've applied is fine with you:
http://git.infradead.org/nvme.git/commitdiff/ed537628e59166a080d618825a7d175565a9cad4
On Mon, Dec 17, 2018 at 08:51:38PM -0800, yupeng wrote:
> +TRACE_EVENT(nvme_sq,
> + TP_PROTO(void *rq_disk, int qid, int sq_head, int sq_tail),
> + TP_ARGS(rq_disk, qid, sq_head, sq_tail),
> + TP_STRUCT__entry(
> + __array(char, disk, DISK_NAME_LEN)
> + __field(int, qid)
> + __field(int, sq_head)
> + __field(int, sq_tail)
> + ),
> + TP_fast_assign(
> + __assign_disk_name(__entry->disk, rq_disk);
> + __entry->qid = qid;
> + __entry->sq_head = sq_head;
> + __entry->sq_tail = sq_tail;
> + ),
> + TP_printk("nvme: %s qid=%d head=%d tail=%d",
> + __print_disk_name(__entry->disk),
No need for a space after the %s. __print_disk_name already appends a
space if there's a disk name, and we don't want the extra space if there
isn't one. Also, every other nvme trace has a ',' after each entry. Not
a big deal, just minor format consistency.
On Tue, Dec 18, 2018 at 10:26:46AM -0700, Keith Busch wrote:
> No need for a space after the %s. __print_disk_name already appends a
> space if there's a disk name, and we don't want the extra space if there
> isn't one. Also, every other nvme trace has a ',' after each entry. Not
> a big deal, just minor format consistency.
Yeah. What about something like this incremental patch to make the
trace formatting and argument passing match what we otherwise do:
diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
index 2477bd906904..5a0bf6a24d50 100644
--- a/drivers/nvme/host/pci.c
+++ b/drivers/nvme/host/pci.c
@@ -1004,8 +1004,7 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
}
req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
- trace_nvme_sq(req->rq_disk, nvmeq->qid, le16_to_cpu(cqe->sq_head),
- nvmeq->sq_tail);
+ trace_nvme_sq(req, cqe->sq_head, nvmeq->sq_tail);
nvme_end_request(req, cqe->status, cqe->result);
}
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index cf666709bc50..3564120aa7b3 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -185,22 +185,24 @@ TRACE_EVENT(nvme_async_event,
#undef aer_name
TRACE_EVENT(nvme_sq,
- TP_PROTO(void *rq_disk, int qid, int sq_head, int sq_tail),
- TP_ARGS(rq_disk, qid, sq_head, sq_tail),
+ TP_PROTO(struct request *req, __le16 sq_head, int sq_tail),
+ TP_ARGS(req, sq_head, sq_tail),
TP_STRUCT__entry(
+ __field(int, ctrl_id)
__array(char, disk, DISK_NAME_LEN)
__field(int, qid)
- __field(int, sq_head)
- __field(int, sq_tail)
+ __field(u16, sq_head)
+ __field(u16, sq_tail)
),
TP_fast_assign(
- __assign_disk_name(__entry->disk, rq_disk);
- __entry->qid = qid;
- __entry->sq_head = sq_head;
+ __entry->ctrl_id = nvme_req(req)->ctrl->instance;
+ __assign_disk_name(__entry->disk, req->rq_disk);
+ __entry->qid = nvme_req_qid(req);
+ __entry->sq_head = le16_to_cpu(sq_head);
__entry->sq_tail = sq_tail;
),
- TP_printk("nvme: %s qid=%d head=%d tail=%d",
- __print_disk_name(__entry->disk),
+ TP_printk("nvme%d: %sqid=%d, head=%u, tail=%u",
+ __entry->ctrl_id, __print_disk_name(__entry->disk),
__entry->qid, __entry->sq_head, __entry->sq_tail
)
);
On Tue, Dec 18, 2018 at 06:47:50PM +0100, [email protected] wrote:
> On Tue, Dec 18, 2018 at 10:26:46AM -0700, Keith Busch wrote:
> > No need for a space after the %s. __print_disk_name already appends a
> > space if there's a disk name, and we don't want the extra space if there
> > isn't one. Also, every other nvme trace has a ',' after each entry. Not
> > a big deal, just minor format consistency.
>
> Yeah. What about something like this incremental patch to make the
> trace formatting and argument passing match what we otherwise do:
Nice, that looks good. It's also necessary for admin commands since
there was no other way to see which controller a completion came from
without this.
Reviewed-by: Keith Busch <[email protected]>
> diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
> index 2477bd906904..5a0bf6a24d50 100644
> --- a/drivers/nvme/host/pci.c
> +++ b/drivers/nvme/host/pci.c
> @@ -1004,8 +1004,7 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
> }
>
> req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
> - trace_nvme_sq(req->rq_disk, nvmeq->qid, le16_to_cpu(cqe->sq_head),
> - nvmeq->sq_tail);
> + trace_nvme_sq(req, cqe->sq_head, nvmeq->sq_tail);
> nvme_end_request(req, cqe->status, cqe->result);
> }
>
> diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
> index cf666709bc50..3564120aa7b3 100644
> --- a/drivers/nvme/host/trace.h
> +++ b/drivers/nvme/host/trace.h
> @@ -185,22 +185,24 @@ TRACE_EVENT(nvme_async_event,
> #undef aer_name
>
> TRACE_EVENT(nvme_sq,
> - TP_PROTO(void *rq_disk, int qid, int sq_head, int sq_tail),
> - TP_ARGS(rq_disk, qid, sq_head, sq_tail),
> + TP_PROTO(struct request *req, __le16 sq_head, int sq_tail),
> + TP_ARGS(req, sq_head, sq_tail),
> TP_STRUCT__entry(
> + __field(int, ctrl_id)
> __array(char, disk, DISK_NAME_LEN)
> __field(int, qid)
> - __field(int, sq_head)
> - __field(int, sq_tail)
> + __field(u16, sq_head)
> + __field(u16, sq_tail)
> ),
> TP_fast_assign(
> - __assign_disk_name(__entry->disk, rq_disk);
> - __entry->qid = qid;
> - __entry->sq_head = sq_head;
> + __entry->ctrl_id = nvme_req(req)->ctrl->instance;
> + __assign_disk_name(__entry->disk, req->rq_disk);
> + __entry->qid = nvme_req_qid(req);
> + __entry->sq_head = le16_to_cpu(sq_head);
> __entry->sq_tail = sq_tail;
> ),
> - TP_printk("nvme: %s qid=%d head=%d tail=%d",
> - __print_disk_name(__entry->disk),
> + TP_printk("nvme%d: %sqid=%d, head=%u, tail=%u",
> + __entry->ctrl_id, __print_disk_name(__entry->disk),
> __entry->qid, __entry->sq_head, __entry->sq_tail
> )
> );
On Tue, Dec 18, 2018 at 9:47 AM [email protected] <[email protected]> wrote:
> diff --git a/drivers/nvme/host/pci.c b/drivers/nvme/host/pci.c
> index 2477bd906904..5a0bf6a24d50 100644
> --- a/drivers/nvme/host/pci.c
> +++ b/drivers/nvme/host/pci.c
> @@ -1004,8 +1004,7 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
> }
>
> req = blk_mq_tag_to_rq(*nvmeq->tags, cqe->command_id);
> - trace_nvme_sq(req->rq_disk, nvmeq->qid, le16_to_cpu(cqe->sq_head),
> - nvmeq->sq_tail);
> + trace_nvme_sq(req, cqe->sq_head, nvmeq->sq_tail);
> nvme_end_request(req, cqe->status, cqe->result);
> }
>
> diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
> index cf666709bc50..3564120aa7b3 100644
> --- a/drivers/nvme/host/trace.h
> +++ b/drivers/nvme/host/trace.h
> @@ -185,22 +185,24 @@ TRACE_EVENT(nvme_async_event,
> #undef aer_name
>
> TRACE_EVENT(nvme_sq,
> - TP_PROTO(void *rq_disk, int qid, int sq_head, int sq_tail),
> - TP_ARGS(rq_disk, qid, sq_head, sq_tail),
> + TP_PROTO(struct request *req, __le16 sq_head, int sq_tail),
> + TP_ARGS(req, sq_head, sq_tail),
> TP_STRUCT__entry(
> + __field(int, ctrl_id)
> __array(char, disk, DISK_NAME_LEN)
> __field(int, qid)
> - __field(int, sq_head)
> - __field(int, sq_tail)
> + __field(u16, sq_head)
> + __field(u16, sq_tail)
> ),
> TP_fast_assign(
> - __assign_disk_name(__entry->disk, rq_disk);
> - __entry->qid = qid;
> - __entry->sq_head = sq_head;
> + __entry->ctrl_id = nvme_req(req)->ctrl->instance;
> + __assign_disk_name(__entry->disk, req->rq_disk);
> + __entry->qid = nvme_req_qid(req);
> + __entry->sq_head = le16_to_cpu(sq_head);
> __entry->sq_tail = sq_tail;
> ),
> - TP_printk("nvme: %s qid=%d head=%d tail=%d",
> - __print_disk_name(__entry->disk),
> + TP_printk("nvme%d: %sqid=%d, head=%u, tail=%u",
> + __entry->ctrl_id, __print_disk_name(__entry->disk),
> __entry->qid, __entry->sq_head, __entry->sq_tail
> )
> );
I think this change is nice. Will you submit this change or are you
suggesting me to do it?
On Tue, Dec 18, 2018 at 05:19:00PM -0800, peng yu wrote:
> I think this change is nice. Will you submit this change or are you
> suggesting me to do it?
I've folded the changes in.