Skip to content

Commit a5448fd

Browse files
minwooimChristoph Hellwig
minwooim
authored and
Christoph Hellwig
committed
nvmet: introduce target-side trace
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 entirely 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 Signed-off-by: Minwoo Im <[email protected]> [hch: fixed the symbol namespace and a an endianess conversion] Signed-off-by: Christoph Hellwig <[email protected]>
1 parent 5f965f4 commit a5448fd

File tree

4 files changed

+353
-0
lines changed

4 files changed

+353
-0
lines changed

‎drivers/nvme/target/Makefile

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,7 @@
11
# SPDX-License-Identifier: GPL-2.0
22

3+
ccflags-y += -I$(src)
4+
35
obj-$(CONFIG_NVME_TARGET) += nvmet.o
46
obj-$(CONFIG_NVME_TARGET_LOOP) += nvme-loop.o
57
obj-$(CONFIG_NVME_TARGET_RDMA) += nvmet-rdma.o
@@ -14,3 +16,4 @@ nvmet-rdma-y += rdma.o
1416
nvmet-fc-y += fc.o
1517
nvme-fcloop-y += fcloop.o
1618
nvmet-tcp-y += tcp.o
19+
nvmet-$(CONFIG_TRACING) += trace.o

‎drivers/nvme/target/core.c

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,9 @@
1010
#include <linux/pci-p2pdma.h>
1111
#include <linux/scatterlist.h>
1212

13+
#define CREATE_TRACE_POINTS
14+
#include "trace.h"
15+
1316
#include "nvmet.h"
1417

1518
struct workqueue_struct *buffered_io_wq;
@@ -691,6 +694,9 @@ static void __nvmet_req_complete(struct nvmet_req *req, u16 status)
691694

692695
if (unlikely(status))
693696
nvmet_set_error(req, status);
697+
698+
trace_nvmet_req_complete(req);
699+
694700
if (req->ns)
695701
nvmet_put_namespace(req->ns);
696702
req->ops->queue_response(req);
@@ -850,6 +856,8 @@ bool nvmet_req_init(struct nvmet_req *req, struct nvmet_cq *cq,
850856
req->error_loc = NVMET_NO_ERROR_LOC;
851857
req->error_slba = 0;
852858

859+
trace_nvmet_req_init(req, req->cmd);
860+
853861
/* no support for fused commands yet */
854862
if (unlikely(flags & (NVME_CMD_FUSE_FIRST | NVME_CMD_FUSE_SECOND))) {
855863
req->error_loc = offsetof(struct nvme_common_command, flags);

‎drivers/nvme/target/trace.c

Lines changed: 201 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,201 @@
1+
// SPDX-License-Identifier: GPL-2.0
2+
/*
3+
* NVM Express target device driver tracepoints
4+
* Copyright (c) 2018 Johannes Thumshirn, SUSE Linux GmbH
5+
*/
6+
7+
#include <asm/unaligned.h>
8+
#include "trace.h"
9+
10+
static const char *nvmet_trace_admin_identify(struct trace_seq *p, u8 *cdw10)
11+
{
12+
const char *ret = trace_seq_buffer_ptr(p);
13+
u8 cns = cdw10[0];
14+
u16 ctrlid = get_unaligned_le16(cdw10 + 2);
15+
16+
trace_seq_printf(p, "cns=%u, ctrlid=%u", cns, ctrlid);
17+
trace_seq_putc(p, 0);
18+
19+
return ret;
20+
}
21+
22+
static const char *nvmet_trace_admin_get_features(struct trace_seq *p,
23+
u8 *cdw10)
24+
{
25+
const char *ret = trace_seq_buffer_ptr(p);
26+
u8 fid = cdw10[0];
27+
u8 sel = cdw10[1] & 0x7;
28+
u32 cdw11 = get_unaligned_le32(cdw10 + 4);
29+
30+
trace_seq_printf(p, "fid=0x%x sel=0x%x cdw11=0x%x", fid, sel, cdw11);
31+
trace_seq_putc(p, 0);
32+
33+
return ret;
34+
}
35+
36+
static const char *nvmet_trace_read_write(struct trace_seq *p, u8 *cdw10)
37+
{
38+
const char *ret = trace_seq_buffer_ptr(p);
39+
u64 slba = get_unaligned_le64(cdw10);
40+
u16 length = get_unaligned_le16(cdw10 + 8);
41+
u16 control = get_unaligned_le16(cdw10 + 10);
42+
u32 dsmgmt = get_unaligned_le32(cdw10 + 12);
43+
u32 reftag = get_unaligned_le32(cdw10 + 16);
44+
45+
trace_seq_printf(p,
46+
"slba=%llu, len=%u, ctrl=0x%x, dsmgmt=%u, reftag=%u",
47+
slba, length, control, dsmgmt, reftag);
48+
trace_seq_putc(p, 0);
49+
50+
return ret;
51+
}
52+
53+
static const char *nvmet_trace_dsm(struct trace_seq *p, u8 *cdw10)
54+
{
55+
const char *ret = trace_seq_buffer_ptr(p);
56+
57+
trace_seq_printf(p, "nr=%u, attributes=%u",
58+
get_unaligned_le32(cdw10),
59+
get_unaligned_le32(cdw10 + 4));
60+
trace_seq_putc(p, 0);
61+
62+
return ret;
63+
}
64+
65+
static const char *nvmet_trace_common(struct trace_seq *p, u8 *cdw10)
66+
{
67+
const char *ret = trace_seq_buffer_ptr(p);
68+
69+
trace_seq_printf(p, "cdw10=%*ph", 24, cdw10);
70+
trace_seq_putc(p, 0);
71+
72+
return ret;
73+
}
74+
75+
const char *nvmet_trace_parse_admin_cmd(struct trace_seq *p,
76+
u8 opcode, u8 *cdw10)
77+
{
78+
switch (opcode) {
79+
case nvme_admin_identify:
80+
return nvmet_trace_admin_identify(p, cdw10);
81+
case nvme_admin_get_features:
82+
return nvmet_trace_admin_get_features(p, cdw10);
83+
default:
84+
return nvmet_trace_common(p, cdw10);
85+
}
86+
}
87+
88+
const char *nvmet_trace_parse_nvm_cmd(struct trace_seq *p,
89+
u8 opcode, u8 *cdw10)
90+
{
91+
switch (opcode) {
92+
case nvme_cmd_read:
93+
case nvme_cmd_write:
94+
case nvme_cmd_write_zeroes:
95+
return nvmet_trace_read_write(p, cdw10);
96+
case nvme_cmd_dsm:
97+
return nvmet_trace_dsm(p, cdw10);
98+
default:
99+
return nvmet_trace_common(p, cdw10);
100+
}
101+
}
102+
103+
static const char *nvmet_trace_fabrics_property_set(struct trace_seq *p,
104+
u8 *spc)
105+
{
106+
const char *ret = trace_seq_buffer_ptr(p);
107+
u8 attrib = spc[0];
108+
u32 ofst = get_unaligned_le32(spc + 4);
109+
u64 value = get_unaligned_le64(spc + 8);
110+
111+
trace_seq_printf(p, "attrib=%u, ofst=0x%x, value=0x%llx",
112+
attrib, ofst, value);
113+
trace_seq_putc(p, 0);
114+
return ret;
115+
}
116+
117+
static const char *nvmet_trace_fabrics_connect(struct trace_seq *p,
118+
u8 *spc)
119+
{
120+
const char *ret = trace_seq_buffer_ptr(p);
121+
u16 recfmt = get_unaligned_le16(spc);
122+
u16 qid = get_unaligned_le16(spc + 2);
123+
u16 sqsize = get_unaligned_le16(spc + 4);
124+
u8 cattr = spc[6];
125+
u32 kato = get_unaligned_le32(spc + 8);
126+
127+
trace_seq_printf(p, "recfmt=%u, qid=%u, sqsize=%u, cattr=%u, kato=%u",
128+
recfmt, qid, sqsize, cattr, kato);
129+
trace_seq_putc(p, 0);
130+
return ret;
131+
}
132+
133+
static const char *nvmet_trace_fabrics_property_get(struct trace_seq *p,
134+
u8 *spc)
135+
{
136+
const char *ret = trace_seq_buffer_ptr(p);
137+
u8 attrib = spc[0];
138+
u32 ofst = get_unaligned_le32(spc + 4);
139+
140+
trace_seq_printf(p, "attrib=%u, ofst=0x%x", attrib, ofst);
141+
trace_seq_putc(p, 0);
142+
return ret;
143+
}
144+
145+
static const char *nvmet_trace_fabrics_common(struct trace_seq *p, u8 *spc)
146+
{
147+
const char *ret = trace_seq_buffer_ptr(p);
148+
149+
trace_seq_printf(p, "spcecific=%*ph", 24, spc);
150+
trace_seq_putc(p, 0);
151+
return ret;
152+
}
153+
154+
const char *nvmet_trace_parse_fabrics_cmd(struct trace_seq *p,
155+
u8 fctype, u8 *spc)
156+
{
157+
switch (fctype) {
158+
case nvme_fabrics_type_property_set:
159+
return nvmet_trace_fabrics_property_set(p, spc);
160+
case nvme_fabrics_type_connect:
161+
return nvmet_trace_fabrics_connect(p, spc);
162+
case nvme_fabrics_type_property_get:
163+
return nvmet_trace_fabrics_property_get(p, spc);
164+
default:
165+
return nvmet_trace_fabrics_common(p, spc);
166+
}
167+
}
168+
169+
const char *nvmet_trace_disk_name(struct trace_seq *p, char *name)
170+
{
171+
const char *ret = trace_seq_buffer_ptr(p);
172+
173+
if (*name)
174+
trace_seq_printf(p, "disk=%s, ", name);
175+
trace_seq_putc(p, 0);
176+
177+
return ret;
178+
}
179+
180+
const char *nvmet_trace_ctrl_name(struct trace_seq *p, struct nvmet_ctrl *ctrl)
181+
{
182+
const char *ret = trace_seq_buffer_ptr(p);
183+
184+
/*
185+
* XXX: We don't know the controller instance before executing the
186+
* connect command itself because the connect command for the admin
187+
* queue will not provide the cntlid which will be allocated in this
188+
* command. In case of io queues, the controller instance will be
189+
* mapped by the extra data of the connect command.
190+
* If we can know the extra data of the connect command in this stage,
191+
* we can update this print statement later.
192+
*/
193+
if (ctrl)
194+
trace_seq_printf(p, "%d", ctrl->cntlid);
195+
else
196+
trace_seq_printf(p, "_");
197+
trace_seq_putc(p, 0);
198+
199+
return ret;
200+
}
201+

‎drivers/nvme/target/trace.h

Lines changed: 141 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,141 @@
1+
/* SPDX-License-Identifier: GPL-2.0 */
2+
/*
3+
* NVM Express target device driver tracepoints
4+
* Copyright (c) 2018 Johannes Thumshirn, SUSE Linux GmbH
5+
*
6+
* This is entirely based on drivers/nvme/host/trace.h
7+
*/
8+
9+
#undef TRACE_SYSTEM
10+
#define TRACE_SYSTEM nvmet
11+
12+
#if !defined(_TRACE_NVMET_H) || defined(TRACE_HEADER_MULTI_READ)
13+
#define _TRACE_NVMET_H
14+
15+
#include <linux/nvme.h>
16+
#include <linux/tracepoint.h>
17+
#include <linux/trace_seq.h>
18+
19+
#include "nvmet.h"
20+
21+
const char *nvmet_trace_parse_admin_cmd(struct trace_seq *p, u8 opcode,
22+
u8 *cdw10);
23+
const char *nvmet_trace_parse_nvm_cmd(struct trace_seq *p, u8 opcode,
24+
u8 *cdw10);
25+
const char *nvmet_trace_parse_fabrics_cmd(struct trace_seq *p, u8 fctype,
26+
u8 *spc);
27+
28+
#define parse_nvme_cmd(qid, opcode, fctype, cdw10) \
29+
((opcode) == nvme_fabrics_command ? \
30+
nvmet_trace_parse_fabrics_cmd(p, fctype, cdw10) : \
31+
(qid ? \
32+
nvmet_trace_parse_nvm_cmd(p, opcode, cdw10) : \
33+
nvmet_trace_parse_admin_cmd(p, opcode, cdw10)))
34+
35+
const char *nvmet_trace_ctrl_name(struct trace_seq *p, struct nvmet_ctrl *ctrl);
36+
#define __print_ctrl_name(ctrl) \
37+
nvmet_trace_ctrl_name(p, ctrl)
38+
39+
const char *nvmet_trace_disk_name(struct trace_seq *p, char *name);
40+
#define __print_disk_name(name) \
41+
nvmet_trace_disk_name(p, name)
42+
43+
#ifndef TRACE_HEADER_MULTI_READ
44+
static inline struct nvmet_ctrl *nvmet_req_to_ctrl(struct nvmet_req *req)
45+
{
46+
return req->sq->ctrl;
47+
}
48+
49+
static inline void __assign_disk_name(char *name, struct nvmet_req *req,
50+
bool init)
51+
{
52+
struct nvmet_ctrl *ctrl = nvmet_req_to_ctrl(req);
53+
struct nvmet_ns *ns;
54+
55+
if ((init && req->sq->qid) || (!init && req->cq->qid)) {
56+
ns = nvmet_find_namespace(ctrl, req->cmd->rw.nsid);
57+
strncpy(name, ns->device_path, DISK_NAME_LEN);
58+
return;
59+
}
60+
61+
memset(name, 0, DISK_NAME_LEN);
62+
}
63+
#endif
64+
65+
TRACE_EVENT(nvmet_req_init,
66+
TP_PROTO(struct nvmet_req *req, struct nvme_command *cmd),
67+
TP_ARGS(req, cmd),
68+
TP_STRUCT__entry(
69+
__field(struct nvme_command *, cmd)
70+
__field(struct nvmet_ctrl *, ctrl)
71+
__array(char, disk, DISK_NAME_LEN)
72+
__field(int, qid)
73+
__field(u16, cid)
74+
__field(u8, opcode)
75+
__field(u8, fctype)
76+
__field(u8, flags)
77+
__field(u32, nsid)
78+
__field(u64, metadata)
79+
__array(u8, cdw10, 24)
80+
),
81+
TP_fast_assign(
82+
__entry->cmd = cmd;
83+
__entry->ctrl = nvmet_req_to_ctrl(req);
84+
__assign_disk_name(__entry->disk, req, true);
85+
__entry->qid = req->sq->qid;
86+
__entry->cid = cmd->common.command_id;
87+
__entry->opcode = cmd->common.opcode;
88+
__entry->fctype = cmd->fabrics.fctype;
89+
__entry->flags = cmd->common.flags;
90+
__entry->nsid = le32_to_cpu(cmd->common.nsid);
91+
__entry->metadata = le64_to_cpu(cmd->common.metadata);
92+
memcpy(__entry->cdw10, &cmd->common.cdw10,
93+
sizeof(__entry->cdw10));
94+
),
95+
TP_printk("nvmet%s: %sqid=%d, cmdid=%u, nsid=%u, flags=%#x, "
96+
"meta=%#llx, cmd=(%s, %s)",
97+
__print_ctrl_name(__entry->ctrl),
98+
__print_disk_name(__entry->disk),
99+
__entry->qid, __entry->cid, __entry->nsid,
100+
__entry->flags, __entry->metadata,
101+
show_opcode_name(__entry->qid, __entry->opcode,
102+
__entry->fctype),
103+
parse_nvme_cmd(__entry->qid, __entry->opcode,
104+
__entry->fctype, __entry->cdw10))
105+
);
106+
107+
TRACE_EVENT(nvmet_req_complete,
108+
TP_PROTO(struct nvmet_req *req),
109+
TP_ARGS(req),
110+
TP_STRUCT__entry(
111+
__field(struct nvmet_ctrl *, ctrl)
112+
__array(char, disk, DISK_NAME_LEN)
113+
__field(int, qid)
114+
__field(int, cid)
115+
__field(u64, result)
116+
__field(u16, status)
117+
),
118+
TP_fast_assign(
119+
__entry->ctrl = nvmet_req_to_ctrl(req);
120+
__entry->qid = req->cq->qid;
121+
__entry->cid = req->cqe->command_id;
122+
__entry->result = le64_to_cpu(req->cqe->result.u64);
123+
__entry->status = le16_to_cpu(req->cqe->status) >> 1;
124+
__assign_disk_name(__entry->disk, req, false);
125+
),
126+
TP_printk("nvmet%s: %sqid=%d, cmdid=%u, res=%#llx, status=%#x",
127+
__print_ctrl_name(__entry->ctrl),
128+
__print_disk_name(__entry->disk),
129+
__entry->qid, __entry->cid, __entry->result, __entry->status)
130+
131+
);
132+
133+
#endif /* _TRACE_NVMET_H */
134+
135+
#undef TRACE_INCLUDE_PATH
136+
#define TRACE_INCLUDE_PATH .
137+
#undef TRACE_INCLUDE_FILE
138+
#define TRACE_INCLUDE_FILE trace
139+
140+
/* This part must be outside protection */
141+
#include <trace/define_trace.h>

0 commit comments

Comments
 (0)