[RFC PATCH V7 0/7] nvme-trace: Add support for fabrics command

[RFC PATCH V7 0/7] nvme-trace: Add support for fabrics command

[Minwoo Im]

Hi,

This is 7th series to support for commands tracing in host and target-side
for not only admin and nvm commands, but also fabrics commands.

This series has been applied suggestion points from Christoph, and it
has added patches for host-side which has exactly the same things with
the target-side as we discussed.

This series has been tested with the target backed loop device, and the
target with RDMA.

Example (RDMA):
  1) target-side
 kworker/0:2-1844  [000] ....    65.451612: nvmet_req_init: nvmet_: qid=0, cmdid=0 cmd=(nvme_fabrics_type_connect, recfmt=0, qid=0, sqsize=31, cattr=0, kato=15000)
kworker/0:1H-1056  [000] ....    65.454270: nvmet_req_complete: nvmet1: qid=0, cmdid=0, res=0xffff888000000001, status=0x0
kworker/0:1H-1056  [000] ....    65.456356: nvmet_req_init: nvmet1: qid=0, cmdid=6 cmd=(nvme_fabrics_type_property_get, attrib=1, ofst=0x0)
kworker/0:1H-1056  [000] ....    65.456663: nvmet_req_complete: nvmet1: qid=0, cmdid=6, res=0x200f0003ff, status=0x0
kworker/0:1H-1056  [000] ....    65.459008: nvmet_req_init: nvmet1: qid=0, cmdid=7 cmd=(nvme_fabrics_type_property_set, attrib=0, ofst=0x14, value=0x460001)
kworker/0:1H-1056  [000] ....    65.459101: nvmet_req_complete: nvmet1: qid=0, cmdid=7, res=0xffff88807ac61420, status=0x0
kworker/0:1H-1056  [000] ....    65.461032: nvmet_req_init: nvmet1: qid=0, cmdid=8 cmd=(nvme_fabrics_type_property_get, attrib=0, ofst=0x1c)
kworker/0:1H-1056  [000] ....    65.461118: nvmet_req_complete: nvmet1: qid=0, cmdid=8, res=0x1, status=0x0
kworker/0:1H-1056  [000] ....    65.462977: nvmet_req_init: nvmet1: qid=0, cmdid=9 cmd=(nvme_fabrics_type_property_get, attrib=0, ofst=0x8)
kworker/0:1H-1056  [000] ....    65.463087: nvmet_req_complete: nvmet1: qid=0, cmdid=9, res=0x10300, status=0x0
kworker/0:1H-1056  [000] ....    65.465135: nvmet_req_init: nvmet1: qid=0, cmdid=6 cmd=(nvme_fabrics_type_property_get, attrib=1, ofst=0x0)
kworker/0:1H-1056  [000] ....    65.465234: nvmet_req_complete: nvmet1: qid=0, cmdid=6, res=0x200f0003ff, status=0x0
...
kworker/0:1H-1056  [000] ....    65.569340: nvmet_req_init: nvmet1: disk=/dev/nvme0n1, qid=6, cmdid=49, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read, slba=0, len=7, ctrl=0x0, dsmgmt=0, reftag=0)
      <idle>-0     [000] d.h.    65.570140: nvmet_req_complete: nvmet1: disk=/dev/nvme0n1, qid=6, cmdid=49, res=0xffff88807a3b8b90, status=0x0
kworker/0:1H-1056  [000] ....    65.573208: nvmet_req_init: nvmet1: disk=/dev/nvme0n1, qid=6, cmdid=50, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read, slba=8, len=7, ctrl=0x0, dsmgmt=0, reftag=0)
      <idle>-0     [000] d.H.    65.573790: nvmet_req_complete: nvmet1: disk=/dev/nvme0n1, qid=6, cmdid=50, res=0xffff88807a3b8ba0, status=0x0
kworker/0:1H-1056  [000] ....    65.585858: nvmet_req_init: nvmet1: disk=/dev/nvme0n1, qid=3, cmdid=1, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read, slba=1048448, len=7, ctrl=0x8000, dsmgmt=7, reftag=0)
      <idle>-0     [000] d.h.    65.586238: nvmet_req_complete: nvmet1: disk=/dev/nvme0n1, qid=3, cmdid=1, res=0xffff88807c9e95c0, status=0x0
kworker/0:1H-1056  [000] ....    65.587726: nvmet_req_init: nvmet1: disk=/dev/nvme0n1, qid=3, cmdid=2, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read, slba=1048560, len=7, ctrl=0x8000, dsmgmt=7, reftag=0)
      <idle>-0     [000] d.h.    65.587982: nvmet_req_complete: nvmet1: disk=/dev/nvme0n1, qid=3, cmdid=2, res=0xffff88807c9e95d0, status=0x0

  2) host-side
  nvme-2318  [007] ....    64.668667: nvme_setup_cmd: nvme0: qid=0, cmdid=0 cmd=(nvme_fabrics_type_connect recfmt=0, qid=0, sqsize=31, cattr=0, kato=15000)
<idle>-0     [007] ..s.    64.673720: nvme_complete_rq: nvme0: qid=0, cmdid=0, res=0xffff888000000001, retries=0, flags=0x0, status=0x0
  nvme-2318  [007] ....    64.673882: nvme_setup_cmd: nvme0: qid=0, cmdid=6 cmd=(nvme_fabrics_type_property_get attrib=1, ofst=0x0)
<idle>-0     [007] ..s.    64.676172: nvme_complete_rq: nvme0: qid=0, cmdid=6, res=0x200f0003ff, retries=0, flags=0x0, status=0x0
  nvme-2318  [007] ....    64.676306: nvme_setup_cmd: nvme0: qid=0, cmdid=7 cmd=(nvme_fabrics_type_property_set attrib=0, ofst=0x14, value=0x460001)
<idle>-0     [007] ..s.    64.678340: nvme_complete_rq: nvme0: qid=0, cmdid=7, res=0xffff88807ac61420, retries=0, flags=0x0, status=0x0
  nvme-2318  [007] ....    64.678363: nvme_setup_cmd: nvme0: qid=0, cmdid=8 cmd=(nvme_fabrics_type_property_get attrib=0, ofst=0x1c)
<idle>-0     [007] ..s.    64.680215: nvme_complete_rq: nvme0: qid=0, cmdid=8, res=0x1, retries=0, flags=0x0, status=0x0
  nvme-2318  [007] ....    64.680240: nvme_setup_cmd: nvme0: qid=0, cmdid=9 cmd=(nvme_fabrics_type_property_get attrib=0, ofst=0x8)
<idle>-0     [007] ..s.    64.682335: nvme_complete_rq: nvme0: qid=0, cmdid=9, res=0x10300, retries=0, flags=0x0, status=0x0
  nvme-2318  [007] ....    64.682474: nvme_setup_cmd: nvme0: qid=0, cmdid=6 cmd=(nvme_fabrics_type_property_get attrib=1, ofst=0x0)
<idle>-0     [007] ..s.    64.684448: nvme_complete_rq: nvme0: qid=0, cmdid=6, res=0x200f0003ff, retries=0, flags=0x0, status=0x0
...
worker/u18:2-1945  [005] ....    64.786215: nvme_setup_cmd: nvme0: disk=nvme0c0n1, qid=6, cmdid=49, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read slba=0, len=7, ctrl=0x0, dsmgmt=0, reftag=0)
      <idle>-0     [005] d.h.    64.790116: nvme_complete_rq: nvme0: disk=nvme0c0n1, qid=6, cmdid=49, res=0xffff88807a3b8b90, retries=0, flags=0x0, status=0x0
worker/u18:2-1945  [005] ....    64.790287: nvme_setup_cmd: nvme0: disk=nvme0c0n1, qid=6, cmdid=50, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read slba=8, len=7, ctrl=0x0, dsmgmt=0, reftag=0)
      <idle>-0     [005] d.h.    64.794233: nvme_complete_rq: nvme0: disk=nvme0c0n1, qid=6, cmdid=50, res=0xffff88807a3b8ba0, retries=0, flags=0x0, status=0x0
ystemd-udevd-2328  [002] ....    64.803350: nvme_setup_cmd: nvme0: disk=nvme0c0n1, qid=3, cmdid=1, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read slba=1048448, len=7, ctrl=0x8000, dsmgmt=7, reftag=0)
      <idle>-0     [000] ..s.    64.805254: nvme_complete_rq: nvme0: disk=nvme0c0n1, qid=3, cmdid=1, res=0xffff88807c9e95c0, retries=0, flags=0x0, status=0x0
ystemd-udevd-2328  [002] ....    64.805389: nvme_setup_cmd: nvme0: disk=nvme0c0n1, qid=3, cmdid=2, nsid=0x1, flags=0x0, meta=0x0 cmd=(nvme_cmd_read slba=1048560, len=7, ctrl=0x8000, dsmgmt=7, reftag=0)
      <idle>-0     [000] ..s.    64.807072: nvme_complete_rq: nvme0: disk=nvme0c0n1, qid=3, cmdid=2, res=0xffff88807c9e95d0, retries=0, flags=0x0, status=0x0

Please review.
Thanks,

Changes to V6:
  - Removed the first patch by a suggestion from Christoph.  The helper
    nvmet_req_to_ctrl() has been moved to the last commit which
    introduces the target-side tracing.
  - Symbolic print for the opcodes for admin, nvm, and fabrics have been
    moved to <linux/nvme.h> to be shared between host and target side.
    It's just a bunch of macros so that we don't share the actual code
    as suggested by Christoph.
  - Print "device_path" when I/O commands come in and out.  The uuid
    will make the trace line too long so that we just can know the
    backed device for the request.
  - From the 2nd patch to 6th patch, they have been added to this series
    to make sure the host-side trace supports the exactly same thing
    with the target-side introduced.

Changes to V5:
  - Provide trace code to the target-side instead of a common code
    shared between host and target to avoid disadvantages something bad
    for the performance like cache miss.  It has been suggested by
    Christoph.
  - Removed the third patch out of this series because that has nothing
    to do with this series.
  - Merged the last two commits into a single commit for the review.

Changes to V4:
  - Add Reviewed-by: tag from Sagi. (Thanks to Sagi)
  - Consider endianness for cqe->status when assigning the value in
    trace
  - Add more descriptions about the variable arguments in events.

Changes to V3:
  - Remove additional argument from the caller level.

Changes to V2:
  - Provide a common code for both host and target. (Chaitanya)
  - Add support for tracing requests in target-side (Chaitanya)
  - Make it simple in trace.h without branch out from nvme core module
    (Christoph)

Changes to V1:
  - fabrics commands should also be decoded, not just showing that it's
    a fabrics command. (Christoph)
  - do not make it within nvme admin commands (Chaitany

Minwoo Im (7):
  nvme: trace: do not EXPORT_SYMBOL for a trace function
  nvme: trace: move opcode symbol print to nvme.h
  nvme: trace: put cid with le16_to_cpu()
  nvme: trace: support for fabrics commands in host-side
  nvme: trace: filter out unnecessary fields for fabrics
  nvme: trace: print result and status in hex format
  nvmet: introduce target-side trace

 drivers/nvme/host/trace.c    |  88 +++++++++++++-
 drivers/nvme/host/trace.h    |  86 ++++----------
 drivers/nvme/target/Makefile |   3 +
 drivers/nvme/target/core.c   |   8 ++
 drivers/nvme/target/trace.c  | 222 +++++++++++++++++++++++++++++++++++
 drivers/nvme/target/trace.h  | 140 ++++++++++++++++++++++
 include/linux/nvme.h         |  59 ++++++++++
 7 files changed, 545 insertions(+), 61 deletions(-)
 create mode 100644 drivers/nvme/target/trace.c
 create mode 100644 drivers/nvme/target/trace.h

--
2.21.0

[RFC PATCH V7 1/7] nvme: trace: do not EXPORT_SYMBOL for a trace function

[Minwoo Im]

nvme_trace_disk_name() is now already being invoked with the function
prototype in trace.h.  We don't need to export this symbol at all.

The following patches are going to provide target-side trace feature
with the exactly same function with this so that this patch removes the
EXPORT_SYMBOL() for this function.

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
Reviewed-by: Christoph Hellwig <hch at lst.de>
Reviewed-by: Chaitanya Kulkarni <chaitanya.kulkarni at wdc.com>
---
 drivers/nvme/host/trace.c | 1 -
 1 file changed, 1 deletion(-)

diff --git a/drivers/nvme/host/trace.c b/drivers/nvme/host/trace.c
index 5f24ea7a28eb..14b0d2993cbe 100644
--- a/drivers/nvme/host/trace.c
+++ b/drivers/nvme/host/trace.c
@@ -145,6 +145,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_GPL(nvme_sq);
-- 
2.21.0

[RFC PATCH V7 2/7] nvme: trace: move opcode symbol print to nvme.h

[Minwoo Im]

The following patches are going to provide the target-side trace which
might need these kind of macros.  It would be great if it can be shared
between host and target side both.

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/host/trace.h | 44 --------------------------------------
 include/linux/nvme.h      | 45 +++++++++++++++++++++++++++++++++++++++
 2 files changed, 45 insertions(+), 44 deletions(-)

diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index e71502d141ed..62ee29107c32 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -16,50 +16,6 @@
 
 #include "nvme.h"
 
-#define nvme_admin_opcode_name(opcode)	{ opcode, #opcode }
-#define show_admin_opcode_name(val)					\
-	__print_symbolic(val,						\
-		nvme_admin_opcode_name(nvme_admin_delete_sq),		\
-		nvme_admin_opcode_name(nvme_admin_create_sq),		\
-		nvme_admin_opcode_name(nvme_admin_get_log_page),	\
-		nvme_admin_opcode_name(nvme_admin_delete_cq),		\
-		nvme_admin_opcode_name(nvme_admin_create_cq),		\
-		nvme_admin_opcode_name(nvme_admin_identify),		\
-		nvme_admin_opcode_name(nvme_admin_abort_cmd),		\
-		nvme_admin_opcode_name(nvme_admin_set_features),	\
-		nvme_admin_opcode_name(nvme_admin_get_features),	\
-		nvme_admin_opcode_name(nvme_admin_async_event),		\
-		nvme_admin_opcode_name(nvme_admin_ns_mgmt),		\
-		nvme_admin_opcode_name(nvme_admin_activate_fw),		\
-		nvme_admin_opcode_name(nvme_admin_download_fw),		\
-		nvme_admin_opcode_name(nvme_admin_ns_attach),		\
-		nvme_admin_opcode_name(nvme_admin_keep_alive),		\
-		nvme_admin_opcode_name(nvme_admin_directive_send),	\
-		nvme_admin_opcode_name(nvme_admin_directive_recv),	\
-		nvme_admin_opcode_name(nvme_admin_dbbuf),		\
-		nvme_admin_opcode_name(nvme_admin_format_nvm),		\
-		nvme_admin_opcode_name(nvme_admin_security_send),	\
-		nvme_admin_opcode_name(nvme_admin_security_recv),	\
-		nvme_admin_opcode_name(nvme_admin_sanitize_nvm))
-
-#define nvme_opcode_name(opcode)	{ opcode, #opcode }
-#define show_nvm_opcode_name(val)				\
-	__print_symbolic(val,					\
-		nvme_opcode_name(nvme_cmd_flush),		\
-		nvme_opcode_name(nvme_cmd_write),		\
-		nvme_opcode_name(nvme_cmd_read),		\
-		nvme_opcode_name(nvme_cmd_write_uncor),		\
-		nvme_opcode_name(nvme_cmd_compare),		\
-		nvme_opcode_name(nvme_cmd_write_zeroes),	\
-		nvme_opcode_name(nvme_cmd_dsm),			\
-		nvme_opcode_name(nvme_cmd_resv_register),	\
-		nvme_opcode_name(nvme_cmd_resv_report),		\
-		nvme_opcode_name(nvme_cmd_resv_acquire),	\
-		nvme_opcode_name(nvme_cmd_resv_release))
-
-#define show_opcode_name(qid, opcode)					\
-	(qid ? show_nvm_opcode_name(opcode) : show_admin_opcode_name(opcode))
-
 const char *nvme_trace_parse_admin_cmd(struct trace_seq *p, u8 opcode,
 		u8 *cdw10);
 const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
diff --git a/include/linux/nvme.h b/include/linux/nvme.h
index 7080923e78d1..86b3d04baf20 100644
--- a/include/linux/nvme.h
+++ b/include/linux/nvme.h
@@ -562,6 +562,22 @@ enum nvme_opcode {
 	nvme_cmd_resv_release	= 0x15,
 };
 
+#define nvme_opcode_name(opcode)	{ opcode, #opcode }
+#define show_nvm_opcode_name(val)				\
+	__print_symbolic(val,					\
+		nvme_opcode_name(nvme_cmd_flush),		\
+		nvme_opcode_name(nvme_cmd_write),		\
+		nvme_opcode_name(nvme_cmd_read),		\
+		nvme_opcode_name(nvme_cmd_write_uncor),		\
+		nvme_opcode_name(nvme_cmd_compare),		\
+		nvme_opcode_name(nvme_cmd_write_zeroes),	\
+		nvme_opcode_name(nvme_cmd_dsm),			\
+		nvme_opcode_name(nvme_cmd_resv_register),	\
+		nvme_opcode_name(nvme_cmd_resv_report),		\
+		nvme_opcode_name(nvme_cmd_resv_acquire),	\
+		nvme_opcode_name(nvme_cmd_resv_release))
+
+
 /*
  * Descriptor subtype - lower 4 bits of nvme_(keyed_)sgl_desc identifier
  *
@@ -794,6 +810,35 @@ enum nvme_admin_opcode {
 	nvme_admin_sanitize_nvm		= 0x84,
 };
 
+#define nvme_admin_opcode_name(opcode)	{ opcode, #opcode }
+#define show_admin_opcode_name(val)					\
+	__print_symbolic(val,						\
+		nvme_admin_opcode_name(nvme_admin_delete_sq),		\
+		nvme_admin_opcode_name(nvme_admin_create_sq),		\
+		nvme_admin_opcode_name(nvme_admin_get_log_page),	\
+		nvme_admin_opcode_name(nvme_admin_delete_cq),		\
+		nvme_admin_opcode_name(nvme_admin_create_cq),		\
+		nvme_admin_opcode_name(nvme_admin_identify),		\
+		nvme_admin_opcode_name(nvme_admin_abort_cmd),		\
+		nvme_admin_opcode_name(nvme_admin_set_features),	\
+		nvme_admin_opcode_name(nvme_admin_get_features),	\
+		nvme_admin_opcode_name(nvme_admin_async_event),		\
+		nvme_admin_opcode_name(nvme_admin_ns_mgmt),		\
+		nvme_admin_opcode_name(nvme_admin_activate_fw),		\
+		nvme_admin_opcode_name(nvme_admin_download_fw),		\
+		nvme_admin_opcode_name(nvme_admin_ns_attach),		\
+		nvme_admin_opcode_name(nvme_admin_keep_alive),		\
+		nvme_admin_opcode_name(nvme_admin_directive_send),	\
+		nvme_admin_opcode_name(nvme_admin_directive_recv),	\
+		nvme_admin_opcode_name(nvme_admin_dbbuf),		\
+		nvme_admin_opcode_name(nvme_admin_format_nvm),		\
+		nvme_admin_opcode_name(nvme_admin_security_send),	\
+		nvme_admin_opcode_name(nvme_admin_security_recv),	\
+		nvme_admin_opcode_name(nvme_admin_sanitize_nvm))
+
+#define show_opcode_name(qid, opcode)					\
+	(qid ? show_nvm_opcode_name(opcode) : show_admin_opcode_name(opcode))
+
 enum {
 	NVME_QUEUE_PHYS_CONTIG	= (1 << 0),
 	NVME_CQ_IRQ_ENABLED	= (1 << 1),
-- 
2.21.0

[RFC PATCH V7 3/7] nvme: trace: put cid with le16_to_cpu()

[Minwoo Im]

The CID(Command Identifier) is in 16bits so that we need to convert it
to cpu's one.

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/host/trace.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 62ee29107c32..59323e68c393 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -59,7 +59,7 @@ TRACE_EVENT(nvme_setup_cmd,
 		__entry->qid = nvme_req_qid(req);
 		__entry->opcode = cmd->common.opcode;
 		__entry->flags = cmd->common.flags;
-		__entry->cid = cmd->common.command_id;
+		__entry->cid = le16_to_cpu(cmd->common.command_id);
 		__entry->nsid = le32_to_cpu(cmd->common.nsid);
 		__entry->metadata = le64_to_cpu(cmd->common.metadata);
 		__assign_disk_name(__entry->disk, req->rq_disk);
-- 
2.21.0

[RFC PATCH V7 4/7] nvme: trace: support for fabrics commands in host-side

[Minwoo Im]

This patch introduces fabrics commands tracing feature from host-side.
This patch does not include any changes for the previous host-side
tracing, but just add fabrics commands parsing in cmd=() format.

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/host/trace.c | 67 +++++++++++++++++++++++++++++++++++++++
 drivers/nvme/host/trace.h | 20 ++++++++----
 include/linux/nvme.h      | 20 ++++++++++--
 3 files changed, 98 insertions(+), 9 deletions(-)

diff --git a/drivers/nvme/host/trace.c b/drivers/nvme/host/trace.c
index 14b0d2993cbe..02c09774ad91 100644
--- a/drivers/nvme/host/trace.c
+++ b/drivers/nvme/host/trace.c
@@ -135,6 +135,73 @@ const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p,
 	}
 }
 
+static const char *nvme_trace_fabrics_property_set(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u8 attrib = spc[0];
+       u32 ofst = get_unaligned_le32(spc + 4);
+       u64 value = get_unaligned_le64(spc + 8);
+
+       trace_seq_printf(p, "attrib=%u, ofst=0x%x, value=0x%llx",
+                               attrib, ofst, value);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_connect(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u16 recfmt = get_unaligned_le16(spc);
+       u16 qid = get_unaligned_le16(spc + 2);
+       u16 sqsize = get_unaligned_le16(spc + 4);
+       u8 cattr = spc[6];
+       u32 kato = get_unaligned_le32(spc + 8);
+
+       trace_seq_printf(p, "recfmt=%u, qid=%u, sqsize=%u, cattr=%u, kato=%u",
+                               recfmt, qid, sqsize, cattr, kato);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_property_get(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u8 attrib = spc[0];
+       u32 ofst = get_unaligned_le32(spc + 4);
+
+       trace_seq_printf(p, "attrib=%u, ofst=0x%x", attrib, ofst);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_common(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+
+       trace_seq_printf(p, "spcecific=%*ph", 24, spc);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+const char *nvme_trace_parse_fabrics_cmd(struct trace_seq *p,
+                                        u8 fctype, u8 *spc)
+{
+       switch (fctype) {
+       case nvme_fabrics_type_property_set:
+               return nvme_trace_fabrics_property_set(p, spc);
+       case nvme_fabrics_type_connect:
+               return nvme_trace_fabrics_connect(p, spc);
+       case nvme_fabrics_type_property_get:
+               return nvme_trace_fabrics_property_get(p, spc);
+       default:
+               return nvme_trace_fabrics_common(p, spc);
+       }
+}
+
 const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
 {
 	const char *ret = trace_seq_buffer_ptr(p);
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index 59323e68c393..da45cef2c31c 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -20,11 +20,15 @@ const char *nvme_trace_parse_admin_cmd(struct trace_seq *p, u8 opcode,
 		u8 *cdw10);
 const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
 		u8 *cdw10);
+const char *nvme_trace_parse_fabrics_cmd(struct trace_seq *p, u8 fctype,
+		u8 *spc);
 
-#define parse_nvme_cmd(qid, opcode, cdw10) 			\
-	(qid ?							\
-	 nvme_trace_parse_nvm_cmd(p, opcode, cdw10) : 		\
-	 nvme_trace_parse_admin_cmd(p, opcode, cdw10))
+#define parse_nvme_cmd(qid, opcode, fctype, cdw10)			\
+	((opcode != nvme_fabrics_command) ?				\
+		(qid ?							\
+			nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
+			nvme_trace_parse_admin_cmd(p, opcode, cdw10)) :	\
+		nvme_trace_parse_fabrics_cmd(p, fctype, cdw10))
 
 const char *nvme_trace_disk_name(struct trace_seq *p, char *name);
 #define __print_disk_name(name)				\
@@ -49,6 +53,7 @@ TRACE_EVENT(nvme_setup_cmd,
 		__field(int, qid)
 		__field(u8, opcode)
 		__field(u8, flags)
+		__field(u8, fctype)
 		__field(u16, cid)
 		__field(u32, nsid)
 		__field(u64, metadata)
@@ -62,6 +67,7 @@ TRACE_EVENT(nvme_setup_cmd,
 		__entry->cid = le16_to_cpu(cmd->common.command_id);
 		__entry->nsid = le32_to_cpu(cmd->common.nsid);
 		__entry->metadata = le64_to_cpu(cmd->common.metadata);
+		__entry->fctype = cmd->fabrics.fctype;
 		__assign_disk_name(__entry->disk, req->rq_disk);
 		memcpy(__entry->cdw10, &cmd->common.cdw10,
 			sizeof(__entry->cdw10));
@@ -70,8 +76,10 @@ TRACE_EVENT(nvme_setup_cmd,
 		      __entry->ctrl_id, __print_disk_name(__entry->disk),
 		      __entry->qid, __entry->cid, __entry->nsid,
 		      __entry->flags, __entry->metadata,
-		      show_opcode_name(__entry->qid, __entry->opcode),
-		      parse_nvme_cmd(__entry->qid, __entry->opcode, __entry->cdw10))
+		      show_opcode_name(__entry->qid, __entry->opcode,
+				__entry->fctype),
+		      parse_nvme_cmd(__entry->qid, __entry->opcode,
+				__entry->fctype, __entry->cdw10))
 );
 
 TRACE_EVENT(nvme_complete_rq,
diff --git a/include/linux/nvme.h b/include/linux/nvme.h
index 86b3d04baf20..6badb45b2889 100644
--- a/include/linux/nvme.h
+++ b/include/linux/nvme.h
@@ -836,9 +836,6 @@ enum nvme_admin_opcode {
 		nvme_admin_opcode_name(nvme_admin_security_recv),	\
 		nvme_admin_opcode_name(nvme_admin_sanitize_nvm))
 
-#define show_opcode_name(qid, opcode)					\
-	(qid ? show_nvm_opcode_name(opcode) : show_admin_opcode_name(opcode))
-
 enum {
 	NVME_QUEUE_PHYS_CONTIG	= (1 << 0),
 	NVME_CQ_IRQ_ENABLED	= (1 << 1),
@@ -1053,6 +1050,23 @@ enum nvmf_capsule_command {
 	nvme_fabrics_type_property_get	= 0x04,
 };
 
+#define nvme_fabrics_type_name(type)   { type, #type }
+#define show_fabrics_type_name(type)                                   \
+       __print_symbolic(type,                                          \
+               nvme_fabrics_type_name(nvme_fabrics_type_property_set), \
+               nvme_fabrics_type_name(nvme_fabrics_type_connect),      \
+               nvme_fabrics_type_name(nvme_fabrics_type_property_get))
+
+/*
+ * If not fabrics command, fctype will be ignored.
+ */
+#define show_opcode_name(qid, opcode, fctype)			\
+	((opcode != nvme_fabrics_command) ?			\
+		(qid ?						\
+			show_nvm_opcode_name(opcode) :		\
+			show_admin_opcode_name(opcode)) :	\
+		show_fabrics_type_name(fctype))
+
 struct nvmf_common_command {
 	__u8	opcode;
 	__u8	resv1;
-- 
2.21.0

[RFC PATCH V7 5/7] nvme: trace: filter out unnecessary fields for fabrics

[Minwoo Im]

If the given command is for fabrics command, then it should not print
out the following fields which are for the !fabrics commands:
  1) "flags" (FUSE, PSDT).
  2) "nsid" which is reserved in fabrics command.
  3) "metadata" which is also reserved in fabrics.

To make !fabrics commands clear, don't print them out in case of fabrics
commands.

Examples:
  1) !fabrics commands (e.g. read):
    nvme_setup_cmd: nvme1: disk=nvme1c1n1, qid=5, cmdid=65, nsid=0x1, flags=0x40, meta=0x0 cmd=(nvme_cmd_read slba=0, len=7, ctrl=0x0, dsmgmt=0, reftag=0)
  2) fabrics commands (e.g. connect):
    nvme_setup_cmd: nvme1: qid=0, cmdid=0 cmd=(nvme_fabrics_type_connect recfmt=0, qid=0, sqsize=31, cattr=0, kato=15000)

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/host/trace.c | 20 ++++++++++++++++++++
 drivers/nvme/host/trace.h | 20 +++++++++++---------
 2 files changed, 31 insertions(+), 9 deletions(-)

diff --git a/drivers/nvme/host/trace.c b/drivers/nvme/host/trace.c
index 02c09774ad91..e5e695b0db80 100644
--- a/drivers/nvme/host/trace.c
+++ b/drivers/nvme/host/trace.c
@@ -213,4 +213,24 @@ const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
 	return ret;
 }
 
+const char *nvme_trace_parse_common(struct trace_seq *p,
+				    struct nvme_command *cmd)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	/*
+	 * Fabrics command capsule does not have the following fields which
+	 * is for !fabrics commands.
+	 */
+	if (!nvme_is_fabrics(cmd)) {
+		trace_seq_printf(p, ", nsid=%#x, flags=%#x, meta=%#llx",
+				le32_to_cpu(cmd->common.nsid),
+				cmd->common.flags,
+				le64_to_cpu(cmd->common.metadata));
+	}
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
 EXPORT_TRACEPOINT_SYMBOL_GPL(nvme_sq);
diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index da45cef2c31c..fd90fc8fd3f7 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -16,6 +16,12 @@
 
 #include "nvme.h"
 
+const char *nvme_trace_parse_common(struct trace_seq *p,
+		struct nvme_command *cmd);
+
+#define parse_nvme_common(cmd)					\
+	nvme_trace_parse_common(p, cmd)
+
 const char *nvme_trace_parse_admin_cmd(struct trace_seq *p, u8 opcode,
 		u8 *cdw10);
 const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
@@ -48,34 +54,30 @@ TRACE_EVENT(nvme_setup_cmd,
 	    TP_PROTO(struct request *req, struct nvme_command *cmd),
 	    TP_ARGS(req, cmd),
 	    TP_STRUCT__entry(
+		__field(struct nvme_command *, cmd)
 		__array(char, disk, DISK_NAME_LEN)
 		__field(int, ctrl_id)
 		__field(int, qid)
 		__field(u8, opcode)
-		__field(u8, flags)
 		__field(u8, fctype)
 		__field(u16, cid)
-		__field(u32, nsid)
-		__field(u64, metadata)
 		__array(u8, cdw10, 24)
 	    ),
 	    TP_fast_assign(
+		__entry->cmd = cmd;
 		__entry->ctrl_id = nvme_req(req)->ctrl->instance;
 		__entry->qid = nvme_req_qid(req);
 		__entry->opcode = cmd->common.opcode;
-		__entry->flags = cmd->common.flags;
 		__entry->cid = le16_to_cpu(cmd->common.command_id);
-		__entry->nsid = le32_to_cpu(cmd->common.nsid);
-		__entry->metadata = le64_to_cpu(cmd->common.metadata);
 		__entry->fctype = cmd->fabrics.fctype;
 		__assign_disk_name(__entry->disk, req->rq_disk);
 		memcpy(__entry->cdw10, &cmd->common.cdw10,
 			sizeof(__entry->cdw10));
 	    ),
-	    TP_printk("nvme%d: %sqid=%d, cmdid=%u, nsid=%u, flags=0x%x, meta=0x%llx, cmd=(%s %s)",
+	    TP_printk("nvme%d: %sqid=%d, cmdid=%u%s cmd=(%s %s)",
 		      __entry->ctrl_id, __print_disk_name(__entry->disk),
-		      __entry->qid, __entry->cid, __entry->nsid,
-		      __entry->flags, __entry->metadata,
+		      __entry->qid, __entry->cid,
+		      parse_nvme_common(__entry->cmd),
 		      show_opcode_name(__entry->qid, __entry->opcode,
 				__entry->fctype),
 		      parse_nvme_cmd(__entry->qid, __entry->opcode,
-- 
2.21.0

[RFC PATCH V7 6/7] nvme: trace: print result and status in hex format

[Minwoo Im]

The "result" field is in 64bit to be printed out which means it could be
like:
  nvme_complete_rq: nvme0: qid=0, cmdid=0, res=18446612684158962624, etries=0, flags=0x0, status=0

Also the "status" field would be great to be parsed if it's in hex
format.

This patch makes them to be printed out in hexa format.

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/host/trace.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/nvme/host/trace.h b/drivers/nvme/host/trace.h
index fd90fc8fd3f7..1f7678d588ce 100644
--- a/drivers/nvme/host/trace.h
+++ b/drivers/nvme/host/trace.h
@@ -107,7 +107,7 @@ TRACE_EVENT(nvme_complete_rq,
 		__entry->status = nvme_req(req)->status;
 		__assign_disk_name(__entry->disk, req->rq_disk);
 	    ),
-	    TP_printk("nvme%d: %sqid=%d, cmdid=%u, res=%llu, retries=%u, flags=0x%x, status=%u",
+	    TP_printk("nvme%d: %sqid=%d, cmdid=%u, res=%#llx, retries=%u, flags=0x%x, status=%#x",
 		      __entry->ctrl_id, __print_disk_name(__entry->disk),
 		      __entry->qid, __entry->cid, __entry->result,
 		      __entry->retries, __entry->flags, __entry->status)
-- 
2.21.0

[RFC PATCH V7 7/7] nvmet: introduce target-side trace

[Minwoo Im]

This patch introduces target-side request tracing.  As Christoph
suggested, the trace would not be in a core or module to avoid
disadvantages like cache miss:
  http://lists.infradead.org/pipermail/linux-nvme/2019-June/024721.html

The target-side trace code is totally based on the Johannes's trace code
from the host side.  It has lots of codes duplicated, but it would be
better than having advantages mentioned above.

It also traces not only fabrics commands, but also nvme normal commands.
Once the codes to be shared gets bigger, then we can make it common as
suggsted.

This also removed the create_sq and create_cq trace parsing functions
because it will be done by the connect fabrics command.

Example:
  echo 1 > /sys/kernel/debug/tracing/event/nvmet/nvmet_req_init/enable
  echo 1 > /sys/kernel/debug/tracing/event/nvmet/nvmet_req_complete/enable
  cat /sys/kernel/debug/tracing/trace

Cc: Keith Busch <kbusch at kernel.org>
Cc: Christoph Hellwig <hch at lst.de>
Cc: Sagi Grimberg <sagi at grimberg.me>
Signed-off-by: Minwoo Im <minwoo.im.dev at gmail.com>
---
 drivers/nvme/target/Makefile |   3 +
 drivers/nvme/target/core.c   |   8 ++
 drivers/nvme/target/trace.c  | 222 +++++++++++++++++++++++++++++++++++
 drivers/nvme/target/trace.h  | 140 ++++++++++++++++++++++
 4 files changed, 373 insertions(+)
 create mode 100644 drivers/nvme/target/trace.c
 create mode 100644 drivers/nvme/target/trace.h

diff --git a/drivers/nvme/target/Makefile b/drivers/nvme/target/Makefile
index 8c3ad0fb6860..2b33836f3d3e 100644
--- a/drivers/nvme/target/Makefile
+++ b/drivers/nvme/target/Makefile
@@ -1,5 +1,7 @@
 # SPDX-License-Identifier: GPL-2.0
 
+ccflags-y				+= -I$(src)
+
 obj-$(CONFIG_NVME_TARGET)		+= nvmet.o
 obj-$(CONFIG_NVME_TARGET_LOOP)		+= nvme-loop.o
 obj-$(CONFIG_NVME_TARGET_RDMA)		+= nvmet-rdma.o
@@ -14,3 +16,4 @@ nvmet-rdma-y	+= rdma.o
 nvmet-fc-y	+= fc.o
 nvme-fcloop-y	+= fcloop.o
 nvmet-tcp-y	+= tcp.o
+nvmet-$(CONFIG_TRACING)	+= trace.o
diff --git a/drivers/nvme/target/core.c b/drivers/nvme/target/core.c
index 0587707b1a25..dad0243c7c96 100644
--- a/drivers/nvme/target/core.c
+++ b/drivers/nvme/target/core.c
@@ -10,6 +10,9 @@
 #include <linux/pci-p2pdma.h>
 #include <linux/scatterlist.h>
 
+#define CREATE_TRACE_POINTS
+#include "trace.h"
+
 #include "nvmet.h"
 
 struct workqueue_struct *buffered_io_wq;
@@ -691,6 +694,9 @@ static void __nvmet_req_complete(struct nvmet_req *req, u16 status)
 
 	if (unlikely(status))
 		nvmet_set_error(req, status);
+
+	trace_nvmet_req_complete(req);
+
 	if (req->ns)
 		nvmet_put_namespace(req->ns);
 	req->ops->queue_response(req);
@@ -850,6 +856,8 @@ bool nvmet_req_init(struct nvmet_req *req, struct nvmet_cq *cq,
 	req->error_loc = NVMET_NO_ERROR_LOC;
 	req->error_slba = 0;
 
+	trace_nvmet_req_init(req, req->cmd);
+
 	/* no support for fused commands yet */
 	if (unlikely(flags & (NVME_CMD_FUSE_FIRST | NVME_CMD_FUSE_SECOND))) {
 		req->error_loc = offsetof(struct nvme_common_command, flags);
diff --git a/drivers/nvme/target/trace.c b/drivers/nvme/target/trace.c
new file mode 100644
index 000000000000..60108fcdf7d5
--- /dev/null
+++ b/drivers/nvme/target/trace.c
@@ -0,0 +1,222 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * NVM Express target device driver tracepoints
+ * Copyright (c) 2018 Johannes Thumshirn, SUSE Linux GmbH
+ */
+
+#include <asm/unaligned.h>
+#include "trace.h"
+
+static const char *nvme_trace_admin_identify(struct trace_seq *p, u8 *cdw10)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+	u8 cns = cdw10[0];
+	u16 ctrlid = get_unaligned_le16(cdw10 + 2);
+
+	trace_seq_printf(p, "cns=%u, ctrlid=%u", cns, ctrlid);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+static const char *nvme_trace_admin_get_features(struct trace_seq *p,
+						 u8 *cdw10)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+	u8 fid = cdw10[0];
+	u8 sel = cdw10[1] & 0x7;
+	u32 cdw11 = get_unaligned_le32(cdw10 + 4);
+
+	trace_seq_printf(p, "fid=0x%x sel=0x%x cdw11=0x%x", fid, sel, cdw11);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+static const char *nvme_trace_read_write(struct trace_seq *p, u8 *cdw10)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+	u64 slba = get_unaligned_le64(cdw10);
+	u16 length = get_unaligned_le16(cdw10 + 8);
+	u16 control = get_unaligned_le16(cdw10 + 10);
+	u32 dsmgmt = get_unaligned_le32(cdw10 + 12);
+	u32 reftag = get_unaligned_le32(cdw10 +  16);
+
+	trace_seq_printf(p,
+			 "slba=%llu, len=%u, ctrl=0x%x, dsmgmt=%u, reftag=%u",
+			 slba, length, control, dsmgmt, reftag);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+static const char *nvme_trace_dsm(struct trace_seq *p, u8 *cdw10)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	trace_seq_printf(p, "nr=%u, attributes=%u",
+			 get_unaligned_le32(cdw10),
+			 get_unaligned_le32(cdw10 + 4));
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+static const char *nvme_trace_common(struct trace_seq *p, u8 *cdw10)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	trace_seq_printf(p, "cdw10=%*ph", 24, cdw10);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+const char *nvme_trace_parse_admin_cmd(struct trace_seq *p,
+				       u8 opcode, u8 *cdw10)
+{
+	switch (opcode) {
+	case nvme_admin_identify:
+		return nvme_trace_admin_identify(p, cdw10);
+	case nvme_admin_get_features:
+		return nvme_trace_admin_get_features(p, cdw10);
+	default:
+		return nvme_trace_common(p, cdw10);
+	}
+}
+
+const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p,
+				     u8 opcode, u8 *cdw10)
+{
+	switch (opcode) {
+	case nvme_cmd_read:
+	case nvme_cmd_write:
+	case nvme_cmd_write_zeroes:
+		return nvme_trace_read_write(p, cdw10);
+	case nvme_cmd_dsm:
+		return nvme_trace_dsm(p, cdw10);
+	default:
+		return nvme_trace_common(p, cdw10);
+	}
+}
+
+static const char *nvme_trace_fabrics_property_set(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u8 attrib = spc[0];
+       u32 ofst = get_unaligned_le32(spc + 4);
+       u64 value = get_unaligned_le64(spc + 8);
+
+       trace_seq_printf(p, "attrib=%u, ofst=0x%x, value=0x%llx",
+                               attrib, ofst, value);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_connect(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u16 recfmt = get_unaligned_le16(spc);
+       u16 qid = get_unaligned_le16(spc + 2);
+       u16 sqsize = get_unaligned_le16(spc + 4);
+       u8 cattr = spc[6];
+       u32 kato = get_unaligned_le32(spc + 8);
+
+       trace_seq_printf(p, "recfmt=%u, qid=%u, sqsize=%u, cattr=%u, kato=%u",
+                               recfmt, qid, sqsize, cattr, kato);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_property_get(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+       u8 attrib = spc[0];
+       u32 ofst = get_unaligned_le32(spc + 4);
+
+       trace_seq_printf(p, "attrib=%u, ofst=0x%x", attrib, ofst);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+static const char *nvme_trace_fabrics_common(struct trace_seq *p, u8 *spc)
+{
+       const char *ret = trace_seq_buffer_ptr(p);
+
+       trace_seq_printf(p, "spcecific=%*ph", 24, spc);
+       trace_seq_putc(p, 0);
+
+       return ret;
+}
+
+const char *nvme_trace_parse_fabrics_cmd(struct trace_seq *p,
+                                        u8 fctype, u8 *spc)
+{
+       switch (fctype) {
+       case nvme_fabrics_type_property_set:
+               return nvme_trace_fabrics_property_set(p, spc);
+       case nvme_fabrics_type_connect:
+               return nvme_trace_fabrics_connect(p, spc);
+       case nvme_fabrics_type_property_get:
+               return nvme_trace_fabrics_property_get(p, spc);
+       default:
+               return nvme_trace_fabrics_common(p, spc);
+       }
+}
+
+const char *nvme_trace_disk_name(struct trace_seq *p, char *name)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	if (*name)
+		trace_seq_printf(p, "disk=%s, ", name);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+const char *nvme_trace_parse_common(struct trace_seq *p,
+				    struct nvme_command *cmd)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	/*
+	 * Fabrics command capsule does not have the following fields which
+	 * is for !fabrics commands.
+	 */
+	if (!nvme_is_fabrics(cmd)) {
+		trace_seq_printf(p, ", nsid=%#x, flags=%#x, meta=%#llx",
+				le32_to_cpu(cmd->common.nsid),
+				cmd->common.flags,
+				le64_to_cpu(cmd->common.metadata));
+	}
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
+const char *nvmet_trace_ctrl_name(struct trace_seq *p, struct nvmet_ctrl *ctrl)
+{
+	const char *ret = trace_seq_buffer_ptr(p);
+
+	/*
+	 * XXX: We don't know the controller instance before executing the
+	 * connect command itself because the connect command for the admin
+	 * queue will not provide the cntlid which will be allocated in this
+	 * command.  In case of io queues, the controller instance will be
+	 * mapped by the extra data of the connect command.
+	 * If we can know the extra data of the connect command in this stage,
+	 * we can update this print statement later.
+	 */
+	if (ctrl)
+		trace_seq_printf(p, "%d", ctrl->cntlid);
+	else
+		trace_seq_printf(p, "_");
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+
diff --git a/drivers/nvme/target/trace.h b/drivers/nvme/target/trace.h
new file mode 100644
index 000000000000..94d5b42d8ff8
--- /dev/null
+++ b/drivers/nvme/target/trace.h
@@ -0,0 +1,140 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * NVM Express target device driver tracepoints
+ * Copyright (c) 2018 Johannes Thumshirn, SUSE Linux GmbH
+ *
+ * This is totally based on drivers/nvme/host/trace.h
+ */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM nvmet
+
+#if !defined(_TRACE_NVMET_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NVMET_H
+
+#include <linux/nvme.h>
+#include <linux/tracepoint.h>
+#include <linux/trace_seq.h>
+
+#include "nvmet.h"
+
+const char *nvme_trace_parse_common(struct trace_seq *p,
+		struct nvme_command *req);
+
+#define parse_nvme_common(cmd)					\
+	nvme_trace_parse_common(p, cmd)
+
+const char *nvme_trace_parse_admin_cmd(struct trace_seq *p, u8 opcode,
+		u8 *cdw10);
+const char *nvme_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
+		u8 *cdw10);
+const char *nvme_trace_parse_fabrics_cmd(struct trace_seq *p, u8 fctype,
+		u8 *spc);
+
+#define parse_nvme_cmd(qid, opcode, fctype, cdw10)			\
+	((opcode != nvme_fabrics_command) ?				\
+		(qid ?							\
+			nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
+			nvme_trace_parse_admin_cmd(p, opcode, cdw10)) :	\
+		nvme_trace_parse_fabrics_cmd(p, fctype, cdw10))
+
+const char *nvmet_trace_ctrl_name(struct trace_seq *p, struct nvmet_ctrl *ctrl);
+#define __print_ctrl_name(ctrl)				\
+	nvmet_trace_ctrl_name(p, ctrl)
+
+const char *nvme_trace_disk_name(struct trace_seq *p, char *name);
+#define __print_disk_name(name)				\
+	nvme_trace_disk_name(p, name)
+
+#ifndef TRACE_HEADER_MULTI_READ
+static inline struct nvmet_ctrl *nvmet_req_to_ctrl(struct nvmet_req *req)
+{
+	return req->sq->ctrl;
+}
+
+static inline void __assign_disk_name(char *name, struct nvmet_req *req,
+		bool init)
+{
+	struct nvmet_ctrl *ctrl = nvmet_req_to_ctrl(req);
+	struct nvmet_ns *ns;
+
+	if ((init && req->sq->qid) || (!init && req->cq->qid)) {
+		ns = nvmet_find_namespace(ctrl, req->cmd->rw.nsid);
+		strncpy(name, ns->device_path, DISK_NAME_LEN);
+		return;
+	}
+
+	memset(name, 0, DISK_NAME_LEN);
+}
+#endif
+
+TRACE_EVENT(nvmet_req_init,
+	TP_PROTO(struct nvmet_req *req, struct nvme_command *cmd),
+	TP_ARGS(req, cmd),
+	TP_STRUCT__entry(
+		__field(struct nvme_command *, cmd)
+		__field(struct nvmet_ctrl *, ctrl)
+		__array(char, disk, DISK_NAME_LEN)
+		__field(int, qid)
+		__field(u16, cid)
+		__field(u8, opcode)
+		__field(u8, fctype)
+		__array(u8, cdw10, 24)
+	),
+	TP_fast_assign(
+		__entry->cmd = cmd;
+		__entry->ctrl = nvmet_req_to_ctrl(req);
+		__assign_disk_name(__entry->disk, req, true);
+		__entry->qid = req->sq->qid;
+		__entry->cid = le16_to_cpu(cmd->common.command_id);
+		__entry->opcode = cmd->common.opcode;
+		__entry->fctype = cmd->fabrics.fctype;
+		memcpy(__entry->cdw10, &cmd->common.cdw10,
+			sizeof(__entry->cdw10));
+	),
+	TP_printk("nvmet%s: %sqid=%d, cmdid=%u%s cmd=(%s, %s)",
+		__print_ctrl_name(__entry->ctrl),
+		__print_disk_name(__entry->disk),
+		__entry->qid, __entry->cid,
+		parse_nvme_common(__entry->cmd),
+		show_opcode_name(__entry->qid, __entry->opcode,
+				__entry->fctype),
+		parse_nvme_cmd(__entry->qid, __entry->opcode,
+				__entry->fctype, __entry->cdw10))
+);
+
+TRACE_EVENT(nvmet_req_complete,
+	TP_PROTO(struct nvmet_req *req),
+	TP_ARGS(req),
+	TP_STRUCT__entry(
+		__field(struct nvmet_ctrl *, ctrl)
+		__array(char, disk, DISK_NAME_LEN)
+		__field(int, qid)
+		__field(int, cid)
+		__field(u64, result)
+		__field(u16, status)
+	),
+	TP_fast_assign(
+		__entry->ctrl = nvmet_req_to_ctrl(req);
+		__entry->qid = req->cq->qid;
+		__entry->cid = req->cqe->command_id;
+		__entry->result = le64_to_cpu(req->cqe->result.u64);
+		__entry->status = le16_to_cpu(req->cqe->status) >> 1;
+		__assign_disk_name(__entry->disk, req, false);
+	),
+	TP_printk("nvmet%s: %sqid=%d, cmdid=%u, res=%#llx, status=%#x",
+		__print_ctrl_name(__entry->ctrl),
+		__print_disk_name(__entry->disk),
+		__entry->qid, __entry->cid, __entry->result, __entry->status)
+
+);
+
+#endif /* _TRACE_NVMET_H */
+
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE trace
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
-- 
2.21.0

[RFC PATCH V7 2/7] nvme: trace: move opcode symbol print to nvme.h

[Christoph Hellwig]

On Fri, Jun 07, 2019@04:45:07AM +0900, Minwoo Im wrote:
> The following patches are going to provide the target-side trace which
> might need these kind of macros.  It would be great if it can be shared
> between host and target side both.

And maybe for some nvme-cli tracing in the future..

Looks good,

Reviewed-by: Christoph Hellwig <hch at lst.de>

[RFC PATCH V7 3/7] nvme: trace: put cid with le16_to_cpu()

[Christoph Hellwig]

On Fri, Jun 07, 2019@04:45:08AM +0900, Minwoo Im wrote:
> The CID(Command Identifier) is in 16bits so that we need to convert it
> to cpu's one.

The command identifier is 16-bits wide, but it is a field that the
controller just passes through and never interprets.  Because of that
it isn't marked as __le16 in nvme.h either.

> -		__entry->cid = cmd->common.command_id;
> +		__entry->cid = le16_to_cpu(cmd->common.command_id);

This will actually create a sparse warning.

[RFC PATCH V7 4/7] nvme: trace: support for fabrics commands in host-side

[Christoph Hellwig]

> +#define parse_nvme_cmd(qid, opcode, fctype, cdw10)			\
> +	((opcode != nvme_fabrics_command) ?				\
> +		(qid ?							\
> +			nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
> +			nvme_trace_parse_admin_cmd(p, opcode, cdw10)) :	\
> +		nvme_trace_parse_fabrics_cmd(p, fctype, cdw10))

The indentation and use of braces looks a little odd here, how about:

#define parse_nvme_cmd(qid, opcode, fctype, cdw10)		\
	((opcode) == nvme_fabrics_command ?			\
	 nvme_trace_parse_fabrics_cmd(p, fctype, cdw10) :	\
	((qid) ?						\
	 nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
	 nvme_trace_parse_admin_cmd(p, opcode, cdw10)))


> +/*
> + * If not fabrics command, fctype will be ignored.
> + */
> +#define show_opcode_name(qid, opcode, fctype)			\
> +	((opcode != nvme_fabrics_command) ?			\
> +		(qid ?						\
> +			show_nvm_opcode_name(opcode) :		\
> +			show_admin_opcode_name(opcode)) :	\
> +		show_fabrics_type_name(fctype))
> +

and:

#define show_opcode_name(qid, opcode, fctype)	\
	((opcode) == nvme_fabrics_command ?	\
	 show_fabrics_type_name(fctype) :	\
	((qid) ?				\
	 show_nvm_opcode_name(opcode) :		\
	 show_admin_opcode_name(opcode)))

Otherwise looks good:

Reviewed-by: Christoph Hellwig <hch at lst.de>

[RFC PATCH V7 5/7] nvme: trace: filter out unnecessary fields for fabrics

[Christoph Hellwig]

On Fri, Jun 07, 2019@04:45:10AM +0900, Minwoo Im wrote:
> If the given command is for fabrics command, then it should not print
> out the following fields which are for the !fabrics commands:
>   1) "flags" (FUSE, PSDT).
>   2) "nsid" which is reserved in fabrics command.
>   3) "metadata" which is also reserved in fabrics.
> 
> To make !fabrics commands clear, don't print them out in case of fabrics
> commands.

Well, they are all reserved and shall be clared to zero.  So I really
don't see any harm in printing them if we can keep the tracing code
simpler and the output more regular.

[RFC PATCH V7 6/7] nvme: trace: print result and status in hex format

[Christoph Hellwig]

Looks good,

Reviewed-by: Christoph Hellwig <hch at lst.de>

[RFC PATCH V7 7/7] nvmet: introduce target-side trace

[Christoph Hellwig]

I'm not a native speaker either, but maybe s/totally/entirely/ in
various places?  Otherwise this looks good modulo the comments to
the previous patches.  Also if someone has a better idea how to
share code without creating a new module or bloating the core
kernel please speak up now.

[RFC PATCH V7 3/7] nvme: trace: put cid with le16_to_cpu()

[Minwoo Im]

On 19-06-07 18:47:23, Christoph Hellwig wrote:
> On Fri, Jun 07, 2019@04:45:08AM +0900, Minwoo Im wrote:
> > The CID(Command Identifier) is in 16bits so that we need to convert it
> > to cpu's one.
> 
> The command identifier is 16-bits wide, but it is a field that the
> controller just passes through and never interprets.  Because of that
> it isn't marked as __le16 in nvme.h either.
> 
> > -		__entry->cid = cmd->common.command_id;
> > +		__entry->cid = le16_to_cpu(cmd->common.command_id);
> 
> This will actually create a sparse warning.

This is a horrible mistake that I made.  Sorry for making confusions.
Please ignore this patch in this series.

Thanks,

[RFC PATCH V7 4/7] nvme: trace: support for fabrics commands in host-side

[Minwoo Im]

On 19-06-07 18:51:56, Christoph Hellwig wrote:
> 
> > +#define parse_nvme_cmd(qid, opcode, fctype, cdw10)			\
> > +	((opcode != nvme_fabrics_command) ?				\
> > +		(qid ?							\
> > +			nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
> > +			nvme_trace_parse_admin_cmd(p, opcode, cdw10)) :	\
> > +		nvme_trace_parse_fabrics_cmd(p, fctype, cdw10))
> 
> The indentation and use of braces looks a little odd here, how about:
> 
> #define parse_nvme_cmd(qid, opcode, fctype, cdw10)		\
> 	((opcode) == nvme_fabrics_command ?			\
> 	 nvme_trace_parse_fabrics_cmd(p, fctype, cdw10) :	\
> 	((qid) ?						\
> 	 nvme_trace_parse_nvm_cmd(p, opcode, cdw10) :	\
> 	 nvme_trace_parse_admin_cmd(p, opcode, cdw10)))
> 
> 
> > +/*
> > + * If not fabrics command, fctype will be ignored.
> > + */
> > +#define show_opcode_name(qid, opcode, fctype)			\
> > +	((opcode != nvme_fabrics_command) ?			\
> > +		(qid ?						\
> > +			show_nvm_opcode_name(opcode) :		\
> > +			show_admin_opcode_name(opcode)) :	\
> > +		show_fabrics_type_name(fctype))
> > +
> 
> and:
> 
> #define show_opcode_name(qid, opcode, fctype)	\
> 	((opcode) == nvme_fabrics_command ?	\
> 	 show_fabrics_type_name(fctype) :	\
> 	((qid) ?				\
> 	 show_nvm_opcode_name(opcode) :		\
> 	 show_admin_opcode_name(opcode)))

I'm actually fine with both.  I was trying to make some depth from the
previous comparisons. But, Okay, will fix this up in next series.

> Otherwise looks good:
> 
> Reviewed-by: Christoph Hellwig <hch at lst.de>

Thanks for your review, Christoph.

Thanks,

[RFC PATCH V7 5/7] nvme: trace: filter out unnecessary fields for fabrics

[Minwoo Im]

On 19-06-07 18:52:44, Christoph Hellwig wrote:
> On Fri, Jun 07, 2019@04:45:10AM +0900, Minwoo Im wrote:
> > If the given command is for fabrics command, then it should not print
> > out the following fields which are for the !fabrics commands:
> >   1) "flags" (FUSE, PSDT).
> >   2) "nsid" which is reserved in fabrics command.
> >   3) "metadata" which is also reserved in fabrics.
> > 
> > To make !fabrics commands clear, don't print them out in case of fabrics
> > commands.
> 
> Well, they are all reserved and shall be clared to zero.  So I really
> don't see any harm in printing them if we can keep the tracing code
> simpler and the output more regular.

Okay with that.  Please let me drop this patch out of this series.

Thanks,

[RFC PATCH V7 7/7] nvmet: introduce target-side trace

[Minwoo Im]

On 19-06-07 18:54:26, Christoph Hellwig wrote:
> I'm not a native speaker either, but maybe s/totally/entirely/ in
> various places?  Otherwise this looks good modulo the comments to
> the previous patches.  Also if someone has a better idea how to
> share code without creating a new module or bloating the core
> kernel please speak up now.

Thanks for letting me know for tht word :)
I can see my words "totally" in the commit message and the header
comment in trace.h top of the file.  I'll fix that up too.

I will prepare the next series if no other comments on this series.  If
any, please give some advices here.

Thanks,

[RFC PATCH V7 2/7] nvme: trace: move opcode symbol print to nvme.h

[Minwoo Im]

On 19-06-07 18:46:14, Christoph Hellwig wrote:
> On Fri, Jun 07, 2019@04:45:07AM +0900, Minwoo Im wrote:
> > The following patches are going to provide the target-side trace which
> > might need these kind of macros.  It would be great if it can be shared
> > between host and target side both.
> 
> And maybe for some nvme-cli tracing in the future..

If you mean some of IOCTLs rather than for the commands, than I
would be happy to go with them after this series.

> Looks good,
> 
> Reviewed-by: Christoph Hellwig <hch at lst.de>

Thanks for your review, by the way.