diff --git a/include/spdk_internal/trace_defs.h b/include/spdk_internal/trace_defs.h index 1b07cc66c..dfe44060b 100644 --- a/include/spdk_internal/trace_defs.h +++ b/include/spdk_internal/trace_defs.h @@ -69,26 +69,30 @@ #define TRACE_BDEV_IO_DONE SPDK_TPOINT_ID(TRACE_GROUP_BDEV, 0x1) /* NVMe-of TCP tracepoint definitions */ -#define TRACE_TCP_REQUEST_STATE_NEW SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0) -#define TRACE_TCP_REQUEST_STATE_NEED_BUFFER SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x1) -#define TRACE_TCP_REQUEST_STATE_TRANSFERRING_HOST_TO_CONTROLLER SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x2) -#define TRACE_TCP_REQUEST_STATE_READY_TO_EXECUTE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x3) -#define TRACE_TCP_REQUEST_STATE_EXECUTING SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x4) -#define TRACE_TCP_REQUEST_STATE_EXECUTED SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x5) -#define TRACE_TCP_REQUEST_STATE_READY_TO_COMPLETE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x6) -#define TRACE_TCP_REQUEST_STATE_TRANSFERRING_CONTROLLER_TO_HOST SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x7) -#define TRACE_TCP_REQUEST_STATE_COMPLETED SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x8) -#define TRACE_TCP_FLUSH_WRITEBUF_START SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x9) -#define TRACE_TCP_FLUSH_WRITEBUF_DONE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xA) -#define TRACE_TCP_READ_FROM_SOCKET_DONE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xB) -#define TRACE_TCP_REQUEST_STATE_AWAIT_R2T_ACK SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xC) -#define TRACE_TCP_QP_CREATE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xD) -#define TRACE_TCP_QP_SOCK_INIT SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xE) -#define TRACE_TCP_QP_STATE_CHANGE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0xF) -#define TRACE_TCP_QP_DISCONNECT SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x10) -#define TRACE_TCP_QP_DESTROY SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x11) -#define TRACE_TCP_QP_ABORT_REQ SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x12) -#define TRACE_TCP_QP_RCV_STATE_CHANGE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x13) +#define TRACE_TCP_REQUEST_STATE_NEW SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x00) +#define TRACE_TCP_REQUEST_STATE_NEED_BUFFER SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x01) +#define TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_START SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x02) +#define TRACE_TCP_REQUEST_STATE_ZCOPY_START_COMPLETED SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x03) +#define TRACE_TCP_REQUEST_STATE_TRANSFERRING_HOST_TO_CONTROLLER SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x04) +#define TRACE_TCP_REQUEST_STATE_READY_TO_EXECUTE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x05) +#define TRACE_TCP_REQUEST_STATE_EXECUTING SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x06) +#define TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_COMMIT SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x07) +#define TRACE_TCP_REQUEST_STATE_EXECUTED SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x08) +#define TRACE_TCP_REQUEST_STATE_READY_TO_COMPLETE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x09) +#define TRACE_TCP_REQUEST_STATE_TRANSFERRING_CONTROLLER_TO_HOST SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0a) +#define TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_RELEASE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0b) +#define TRACE_TCP_REQUEST_STATE_COMPLETED SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0c) +#define TRACE_TCP_FLUSH_WRITEBUF_START SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0d) +#define TRACE_TCP_FLUSH_WRITEBUF_DONE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0e) +#define TRACE_TCP_READ_FROM_SOCKET_DONE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x0f) +#define TRACE_TCP_REQUEST_STATE_AWAIT_R2T_ACK SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x10) +#define TRACE_TCP_QP_CREATE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x11) +#define TRACE_TCP_QP_SOCK_INIT SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x12) +#define TRACE_TCP_QP_STATE_CHANGE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x13) +#define TRACE_TCP_QP_DISCONNECT SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x14) +#define TRACE_TCP_QP_DESTROY SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x15) +#define TRACE_TCP_QP_ABORT_REQ SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x16) +#define TRACE_TCP_QP_RCV_STATE_CHANGE SPDK_TPOINT_ID(TRACE_GROUP_NVMF_TCP, 0x17) /* NVMe-of RDMA tracepoint definitions */ #define TRACE_RDMA_REQUEST_STATE_NEW SPDK_TPOINT_ID(TRACE_GROUP_NVMF_RDMA, 0x0) diff --git a/lib/nvmf/tcp.c b/lib/nvmf/tcp.c index 9e501f868..e09d058b0 100644 --- a/lib/nvmf/tcp.c +++ b/lib/nvmf/tcp.c @@ -131,6 +131,14 @@ SPDK_TRACE_REGISTER_FN(nvmf_tcp_trace, "nvmf_tcp", TRACE_GROUP_NVMF_TCP) TRACE_TCP_REQUEST_STATE_NEED_BUFFER, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, SPDK_TRACE_ARG_TYPE_PTR, "qpair"); + spdk_trace_register_description("TCP_REQ_WAIT_ZCPY_START", + TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_START, + OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, + SPDK_TRACE_ARG_TYPE_PTR, "qpair"); + spdk_trace_register_description("TCP_REQ_ZCPY_START_CPL", + TRACE_TCP_REQUEST_STATE_ZCOPY_START_COMPLETED, + OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, + SPDK_TRACE_ARG_TYPE_PTR, "qpair"); spdk_trace_register_description("TCP_REQ_TX_H_TO_C", TRACE_TCP_REQUEST_STATE_TRANSFERRING_HOST_TO_CONTROLLER, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, @@ -143,6 +151,10 @@ SPDK_TRACE_REGISTER_FN(nvmf_tcp_trace, "nvmf_tcp", TRACE_GROUP_NVMF_TCP) TRACE_TCP_REQUEST_STATE_EXECUTING, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, SPDK_TRACE_ARG_TYPE_PTR, "qpair"); + spdk_trace_register_description("TCP_REQ_WAIT_ZCPY_CMT", + TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_COMMIT, + OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, + SPDK_TRACE_ARG_TYPE_PTR, "qpair"); spdk_trace_register_description("TCP_REQ_EXECUTED", TRACE_TCP_REQUEST_STATE_EXECUTED, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, @@ -155,6 +167,10 @@ SPDK_TRACE_REGISTER_FN(nvmf_tcp_trace, "nvmf_tcp", TRACE_GROUP_NVMF_TCP) TRACE_TCP_REQUEST_STATE_TRANSFERRING_CONTROLLER_TO_HOST, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, SPDK_TRACE_ARG_TYPE_PTR, "qpair"); + spdk_trace_register_description("TCP_REQ_AWAIT_ZCPY_RLS", + TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_RELEASE, + OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, + SPDK_TRACE_ARG_TYPE_PTR, "qpair"); spdk_trace_register_description("TCP_REQ_COMPLETED", TRACE_TCP_REQUEST_STATE_COMPLETED, OWNER_NONE, OBJECT_NVMF_TCP_IO, 0, @@ -2681,10 +2697,14 @@ nvmf_tcp_req_process(struct spdk_nvmf_tcp_transport *ttransport, nvmf_tcp_req_set_state(tcp_req, TCP_REQUEST_STATE_READY_TO_EXECUTE); break; case TCP_REQUEST_STATE_AWAITING_ZCOPY_START: + spdk_trace_record(TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_START, 0, 0, + (uintptr_t)tcp_req, tqpair); /* Some external code must kick a request into TCP_REQUEST_STATE_ZCOPY_START_COMPLETED * to escape this state. */ break; case TCP_REQUEST_STATE_ZCOPY_START_COMPLETED: + spdk_trace_record(TRACE_TCP_REQUEST_STATE_ZCOPY_START_COMPLETED, 0, 0, + (uintptr_t)tcp_req, tqpair); if (spdk_unlikely(spdk_nvme_cpl_is_error(&tcp_req->req.rsp->nvme_cpl))) { SPDK_DEBUGLOG(nvmf_tcp, "Zero-copy start failed for tcp_req(%p) on tqpair=%p\n", tcp_req, tqpair); @@ -2736,6 +2756,8 @@ nvmf_tcp_req_process(struct spdk_nvmf_tcp_transport *ttransport, * to escape this state. */ break; case TCP_REQUEST_STATE_AWAITING_ZCOPY_COMMIT: + spdk_trace_record(TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_COMMIT, 0, 0, + (uintptr_t)tcp_req, tqpair); /* Some external code must kick a request into TCP_REQUEST_STATE_EXECUTED * to escape this state. */ break; @@ -2761,6 +2783,8 @@ nvmf_tcp_req_process(struct spdk_nvmf_tcp_transport *ttransport, * to escape this state. */ break; case TCP_REQUEST_STATE_AWAITING_ZCOPY_RELEASE: + spdk_trace_record(TRACE_TCP_REQUEST_STATE_AWAIT_ZCOPY_RELEASE, 0, 0, + (uintptr_t)tcp_req, tqpair); /* Some external code must kick a request into TCP_REQUEST_STATE_COMPLETED * to escape this state. */ break;