Skip to contentSkip to conversation

export trace.c helper functions to other modules

PATCH In review yupeng 4 participants 13 messages Dec 18, 2018 – Dec 19, 2018

Subsystems (2)
Block layer NVMe
lore
Share & tools
lore

yupeng

author
#0 lore raw

PATCH v4 1/2 export trace.c helper functions to other modules

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 <yupeng0921 at gmail.com>
---
 drivers/nvme/host/trace.c | 3 +++
 1 file changed, 3 insertions(+)
drivers/nvme/host/trace.c +3 -0
index 25b0e310f4a8..8ca7079ed2bc 100644
@@ -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);
Signature · 1 line
2.17.1
author
#1 lore raw

PATCH v4 2/2 trace nvme submit queue status

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 <yupeng0921 at gmail.com>
---
 drivers/nvme/host/pci.c   |  5 +++++
 drivers/nvme/host/trace.c |  2 ++
 drivers/nvme/host/trace.h | 21 +++++++++++++++++++++
 3 files changed, 28 insertions(+)
drivers/nvme/host/pci.c +5 -0
index c33bb201b884..52df2f7fef37 100644
@@ -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);
 }
drivers/nvme/host/trace.c +2 -0
index 8ca7079ed2bc..7bfaace23e1e 100644
@@ -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);
drivers/nvme/host/trace.h +21 -0
index 196d5bd56718..3606cd7000f4 100644
@@ -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
Signature · 1 line
2.17.1
maintainer Reviewed-by on v4 2/2
#2 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

drivers/nvme/host/pci.c static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx) · line 906

Quoted 9 lines
drivers/nvme/host/pci.c +4 -0
@@ -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 <sagi at grimberg.me>
author
#3 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

Quoted 5 lines · Sagi Grimberg
Quoted 5 lines
(quoted diff) +0 -0
@@ -899,6 +900,10 @@ static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx)
      }
Quoted 8 lines

drivers/nvme/host/pci.c static inline void nvme_handle_cqe(struct nvme_queue *nvmeq, u16 idx) · line 906

Quoted 5 lines
drivers/nvme/host/pci.c +4 -0
      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.

maintainer
#4 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

Quoted 10 lines · peng yu

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

#5 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

In reply to yupeng
Quoted 7 lines · yupeng
drivers/nvme/host/trace.h +7 -0
+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)

drivers/nvme/host/trace.h TRACE_EVENT(nvme_async_event, · line 203

Quoted 10 lines
drivers/nvme/host/trace.h +10 -0
+		__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.

maintainer
#6 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

Quoted 4 lines · Keith Busch

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:

drivers/nvme/host/pci.c +1 -2
index 2477bd906904..5a0bf6a24d50 100644
@@ -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);
 }
drivers/nvme/host/trace.h +11 -9
index cf666709bc50..3564120aa7b3 100644
@@ -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
 	)
 );
Reviewed-by
#7 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

Quoted 8 lines · On Tue, Dec 18, 2018@06:47:50PM +0100, [email protected] wrote:
Quoted 4 lines · Keith Busch

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 <keith.busch at intel.com>
Quoted 52 lines
drivers/nvme/host/pci.c +1 -2
index 2477bd906904..5a0bf6a24d50 100644
@@ -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);
 }
drivers/nvme/host/trace.h +11 -9
index cf666709bc50..3564120aa7b3 100644
@@ -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
 	)
 );
author
#8 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

In reply to [email protected]
Quoted 42 lines · On Tue, Dec 18, 2018@9:47 AM [email protected] <[email protected]> wrote:
drivers/nvme/host/pci.c +1 -2
index 2477bd906904..5a0bf6a24d50 100644
@@ -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);
 }
drivers/nvme/host/trace.h +8 -7
index cf666709bc50..3564120aa7b3 100644
@@ -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);

drivers/nvme/host/trace.h TRACE_EVENT(nvme_async_event, · line 208

Quoted 10 lines
drivers/nvme/host/trace.h +3 -2
+               __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?

maintainer
#9 lore raw

Re: [PATCH v4 2/2] trace nvme submit queue status

Quoted 2 lines · peng yu

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.

maintainer
#11 lore raw
In reply to yupeng
Quoted 6 lines · yupeng

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?

maintainer
#12 lore raw
Quoted 10 lines · Christoph Hellwig
Quoted 6 lines · yupeng

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

Quoted 2 lines

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.