From 971f07b9fb3b694b1d0ab1eddf37ac3a7628c758 Mon Sep 17 00:00:00 2001 From: Jim Harris Date: Wed, 25 Aug 2021 10:04:51 -0700 Subject: [PATCH] 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 Change-Id: Ie2543cadf3541eb74398d31ac0f495522ab49ec0 Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/9303 Community-CI: Broadcom CI Community-CI: Mellanox Build Bot Tested-by: SPDK CI Jenkins Reviewed-by: Changpeng Liu Reviewed-by: Tomasz Zawadzki --- lib/nvme/nvme_pcie_common.c | 38 +++++++++++++++++++ mk/spdk.lib_deps.mk | 2 +- .../nvme_pcie_common.c/nvme_pcie_common_ut.c | 1 + 3 files changed, 40 insertions(+), 1 deletion(-) diff --git a/lib/nvme/nvme_pcie_common.c b/lib/nvme/nvme_pcie_common.c index 1e6154526..aeee15543 100644 --- a/lib/nvme/nvme_pcie_common.c +++ b/lib/nvme/nvme_pcie_common.c @@ -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)); +} diff --git a/mk/spdk.lib_deps.mk b/mk/spdk.lib_deps.mk index fe9cb621e..68fd1a97a 100644 --- a/mk/spdk.lib_deps.mk +++ b/mk/spdk.lib_deps.mk @@ -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 diff --git a/test/unit/lib/nvme/nvme_pcie_common.c/nvme_pcie_common_ut.c b/test/unit/lib/nvme/nvme_pcie_common.c/nvme_pcie_common_ut.c index 134447e01..3bf350936 100644 --- a/test/unit/lib/nvme/nvme_pcie_common.c/nvme_pcie_common_ut.c +++ b/test/unit/lib/nvme/nvme_pcie_common.c/nvme_pcie_common_ut.c @@ -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,