nvme: add tracing to pcie request path

John Kariuki tested this patch on a system with
several Intel P5800X Optane SSDs, to determine the
performance impact of adding these two
spdk_trace_records() in the main NVMe I/O path.

The pathological case (512B random reads on a single
Xeon core) decreased from 13.10M to 12.88M, or 1.7%.
Normal workloads (4KB+) would incur a smaller penalty
since the I/O rate would be much lower - maybe even
unnoticeable..

This is a really valuable tracepoint to have enabled
by default, so I think this small amount of degradation
is acceptable.

Signed-off-by: Jim Harris <james.r.harris@intel.com>
Change-Id: Ie2543cadf3541eb74398d31ac0f495522ab49ec0

Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/9303
Community-CI: Broadcom CI <spdk-ci.pdl@broadcom.com>
Community-CI: Mellanox Build Bot
Tested-by: SPDK CI Jenkins <sys_sgci@intel.com>
Reviewed-by: Changpeng Liu <changpeng.liu@intel.com>
Reviewed-by: Tomasz Zawadzki <tomasz.zawadzki@intel.com>
This commit is contained in:
Jim Harris 2021-08-25 10:04:51 -07:00 committed by Tomasz Zawadzki
parent 6b79ee126b
commit 971f07b9fb
3 changed files with 40 additions and 1 deletions

View File

@ -40,6 +40,14 @@
#include "spdk/string.h"
#include "nvme_internal.h"
#include "nvme_pcie_internal.h"
#include "spdk/trace.h"
#define OBJECT_NVME_PCIE_TR 0x3
#define OWNER_NVME_PCIE_QP 0x3
#define TRACE_GROUP_NVME_PCIE 0xB
#define TRACE_NVME_PCIE_SUBMIT SPDK_TPOINT_ID(TRACE_GROUP_NVME_PCIE, 0x0)
#define TRACE_NVME_PCIE_COMPLETE SPDK_TPOINT_ID(TRACE_GROUP_NVME_PCIE, 0x1)
__thread struct nvme_pcie_ctrlr *g_thread_mmio_ctrlr = NULL;
@ -646,6 +654,9 @@ nvme_pcie_qpair_submit_tracker(struct spdk_nvme_qpair *qpair, struct nvme_tracke
req = tr->req;
assert(req != NULL);
spdk_trace_record(TRACE_NVME_PCIE_SUBMIT, qpair->id, 0, (uintptr_t)req,
req->cmd.cid, req->cmd.opc, req->cmd.cdw10, req->cmd.cdw11, req->cmd.cdw12);
if (req->cmd.fuse == SPDK_NVME_IO_FLAGS_FUSE_FIRST) {
/* This is first cmd of two fused commands - don't ring doorbell */
qpair->first_fused_submitted = 1;
@ -686,6 +697,8 @@ nvme_pcie_qpair_complete_tracker(struct spdk_nvme_qpair *qpair, struct nvme_trac
req = tr->req;
spdk_trace_record(TRACE_NVME_PCIE_COMPLETE, qpair->id, 0, (uintptr_t)req, req->cmd.cid);
assert(req != NULL);
error = spdk_nvme_cpl_is_error(cpl);
@ -1754,3 +1767,28 @@ nvme_pcie_poll_group_destroy(struct spdk_nvme_transport_poll_group *tgroup)
return 0;
}
SPDK_TRACE_REGISTER_FN(nvme_pcie, "nvme_pcie", TRACE_GROUP_NVME_PCIE)
{
struct spdk_trace_tpoint_opts opts[] = {
{
"NVME_PCIE_SUBMIT", TRACE_NVME_PCIE_SUBMIT,
OWNER_NVME_PCIE_QP, OBJECT_NVME_PCIE_TR, 1,
{ { "cid", SPDK_TRACE_ARG_TYPE_INT, 8 },
{ "opc", SPDK_TRACE_ARG_TYPE_INT, 8 },
{ "dw10", SPDK_TRACE_ARG_TYPE_PTR, 8 },
{ "dw11", SPDK_TRACE_ARG_TYPE_PTR, 8 },
{ "dw12", SPDK_TRACE_ARG_TYPE_PTR, 8 }
}
},
{
"NVME_PCIE_COMPLETE", TRACE_NVME_PCIE_COMPLETE,
OWNER_NVME_PCIE_QP, OBJECT_NVME_PCIE_TR, 0,
{{ "cid", SPDK_TRACE_ARG_TYPE_INT, 8 }}
},
};
spdk_trace_register_object(OBJECT_NVME_PCIE_TR, 'p');
spdk_trace_register_owner(OWNER_NVME_PCIE_QP, 'q');
spdk_trace_register_description_ext(opts, SPDK_COUNTOF(opts));
}

View File

@ -62,7 +62,7 @@ DEPDIRS-rdma := log util
DEPDIRS-reduce := log util
DEPDIRS-thread := log util trace
DEPDIRS-nvme := log sock util
DEPDIRS-nvme := log sock util trace
ifeq ($(CONFIG_RDMA),y)
DEPDIRS-nvme += rdma dma
endif

View File

@ -72,6 +72,7 @@ DEFINE_STUB(spdk_nvme_qpair_process_completions, int32_t,
DEFINE_STUB(nvme_request_check_timeout, int, (struct nvme_request *req, uint16_t cid,
struct spdk_nvme_ctrlr_process *active_proc, uint64_t now_tick), 0);
DEFINE_STUB(spdk_strerror, const char *, (int errnum), NULL);
int nvme_qpair_init(struct spdk_nvme_qpair *qpair, uint16_t id,
struct spdk_nvme_ctrlr *ctrlr,