From 6ceea36890a01aa626ce08487eecc5fb43e749b1 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 19 Dec 2018 10:58:24 -0500 Subject: xprtrdma: Refactor Receive accounting Clean up: Divide the work cleanly: - rpcrdma_wc_receive is responsible only for RDMA Receives - rpcrdma_reply_handler is responsible only for RPC Replies - the posted send and receive counts both belong in rpcrdma_ep Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index b093058f78aa..2efe2d7d6683 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -570,7 +570,7 @@ TRACE_EVENT(xprtrdma_post_recvs, __entry->r_xprt = r_xprt; __entry->count = count; __entry->status = status; - __entry->posted = r_xprt->rx_buf.rb_posted_receives; + __entry->posted = r_xprt->rx_ep.rep_receive_count; __assign_str(addr, rpcrdma_addrstr(r_xprt)); __assign_str(port, rpcrdma_portstr(r_xprt)); ), -- cgit v1.2.3 From aba11831794356ff58da69de46a125e6335eb9ca Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 19 Dec 2018 10:59:49 -0500 Subject: xprtrdma: Clean up of xprtrdma chunk trace points The chunk-related trace points capture nearly the same information as the MR-related trace points. Also, rename them so globbing can be used to enable or disable these trace points more easily. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 42 ++++++++++++++++++++++++++---------------- 1 file changed, 26 insertions(+), 16 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index 2efe2d7d6683..e9fbf7dbc16f 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -97,7 +97,6 @@ DECLARE_EVENT_CLASS(xprtrdma_rdch_event, TP_STRUCT__entry( __field(unsigned int, task_id) __field(unsigned int, client_id) - __field(const void *, mr) __field(unsigned int, pos) __field(int, nents) __field(u32, handle) @@ -109,7 +108,6 @@ DECLARE_EVENT_CLASS(xprtrdma_rdch_event, TP_fast_assign( __entry->task_id = task->tk_pid; __entry->client_id = task->tk_client->cl_clid; - __entry->mr = mr; __entry->pos = pos; __entry->nents = mr->mr_nents; __entry->handle = mr->mr_handle; @@ -118,8 +116,8 @@ DECLARE_EVENT_CLASS(xprtrdma_rdch_event, __entry->nsegs = nsegs; ), - TP_printk("task:%u@%u mr=%p pos=%u %u@0x%016llx:0x%08x (%s)", - __entry->task_id, __entry->client_id, __entry->mr, + TP_printk("task:%u@%u pos=%u %u@0x%016llx:0x%08x (%s)", + __entry->task_id, __entry->client_id, __entry->pos, __entry->length, (unsigned long long)__entry->offset, __entry->handle, __entry->nents < __entry->nsegs ? "more" : "last" @@ -127,7 +125,7 @@ DECLARE_EVENT_CLASS(xprtrdma_rdch_event, ); #define DEFINE_RDCH_EVENT(name) \ - DEFINE_EVENT(xprtrdma_rdch_event, name, \ + DEFINE_EVENT(xprtrdma_rdch_event, xprtrdma_chunk_##name,\ TP_PROTO( \ const struct rpc_task *task, \ unsigned int pos, \ @@ -148,7 +146,6 @@ DECLARE_EVENT_CLASS(xprtrdma_wrch_event, TP_STRUCT__entry( __field(unsigned int, task_id) __field(unsigned int, client_id) - __field(const void *, mr) __field(int, nents) __field(u32, handle) __field(u32, length) @@ -159,7 +156,6 @@ DECLARE_EVENT_CLASS(xprtrdma_wrch_event, TP_fast_assign( __entry->task_id = task->tk_pid; __entry->client_id = task->tk_client->cl_clid; - __entry->mr = mr; __entry->nents = mr->mr_nents; __entry->handle = mr->mr_handle; __entry->length = mr->mr_length; @@ -167,8 +163,8 @@ DECLARE_EVENT_CLASS(xprtrdma_wrch_event, __entry->nsegs = nsegs; ), - TP_printk("task:%u@%u mr=%p %u@0x%016llx:0x%08x (%s)", - __entry->task_id, __entry->client_id, __entry->mr, + TP_printk("task:%u@%u %u@0x%016llx:0x%08x (%s)", + __entry->task_id, __entry->client_id, __entry->length, (unsigned long long)__entry->offset, __entry->handle, __entry->nents < __entry->nsegs ? "more" : "last" @@ -176,7 +172,7 @@ DECLARE_EVENT_CLASS(xprtrdma_wrch_event, ); #define DEFINE_WRCH_EVENT(name) \ - DEFINE_EVENT(xprtrdma_wrch_event, name, \ + DEFINE_EVENT(xprtrdma_wrch_event, xprtrdma_chunk_##name,\ TP_PROTO( \ const struct rpc_task *task, \ struct rpcrdma_mr *mr, \ @@ -234,6 +230,18 @@ DECLARE_EVENT_CLASS(xprtrdma_frwr_done, ), \ TP_ARGS(wc, frwr)) +TRACE_DEFINE_ENUM(DMA_BIDIRECTIONAL); +TRACE_DEFINE_ENUM(DMA_TO_DEVICE); +TRACE_DEFINE_ENUM(DMA_FROM_DEVICE); +TRACE_DEFINE_ENUM(DMA_NONE); + +#define xprtrdma_show_direction(x) \ + __print_symbolic(x, \ + { DMA_BIDIRECTIONAL, "BIDIR" }, \ + { DMA_TO_DEVICE, "TO_DEVICE" }, \ + { DMA_FROM_DEVICE, "FROM_DEVICE" }, \ + { DMA_NONE, "NONE" }) + DECLARE_EVENT_CLASS(xprtrdma_mr, TP_PROTO( const struct rpcrdma_mr *mr @@ -246,6 +254,7 @@ DECLARE_EVENT_CLASS(xprtrdma_mr, __field(u32, handle) __field(u32, length) __field(u64, offset) + __field(u32, dir) ), TP_fast_assign( @@ -253,12 +262,13 @@ DECLARE_EVENT_CLASS(xprtrdma_mr, __entry->handle = mr->mr_handle; __entry->length = mr->mr_length; __entry->offset = mr->mr_offset; + __entry->dir = mr->mr_dir; ), - TP_printk("mr=%p %u@0x%016llx:0x%08x", + TP_printk("mr=%p %u@0x%016llx:0x%08x (%s)", __entry->mr, __entry->length, - (unsigned long long)__entry->offset, - __entry->handle + (unsigned long long)__entry->offset, __entry->handle, + xprtrdma_show_direction(__entry->dir) ) ); @@ -437,9 +447,9 @@ TRACE_EVENT(xprtrdma_createmrs, DEFINE_RXPRT_EVENT(xprtrdma_nomrs); -DEFINE_RDCH_EVENT(xprtrdma_read_chunk); -DEFINE_WRCH_EVENT(xprtrdma_write_chunk); -DEFINE_WRCH_EVENT(xprtrdma_reply_chunk); +DEFINE_RDCH_EVENT(read); +DEFINE_WRCH_EVENT(write); +DEFINE_WRCH_EVENT(reply); TRACE_DEFINE_ENUM(rpcrdma_noch); TRACE_DEFINE_ENUM(rpcrdma_readch); -- cgit v1.2.3 From 395069fc37e7a76280b176c0327d1ead6ca29838 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 19 Dec 2018 11:00:00 -0500 Subject: xprtrdma: Add trace points for calls to transport switch methods Name them "trace_xprtrdma_op_*" so they can be easily enabled as a group. No trace point is added where the generic layer already has observability. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index e9fbf7dbc16f..3d068bba4532 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -381,11 +381,13 @@ TRACE_EVENT(xprtrdma_disconnect, DEFINE_RXPRT_EVENT(xprtrdma_conn_start); DEFINE_RXPRT_EVENT(xprtrdma_conn_tout); DEFINE_RXPRT_EVENT(xprtrdma_create); -DEFINE_RXPRT_EVENT(xprtrdma_destroy); +DEFINE_RXPRT_EVENT(xprtrdma_op_destroy); DEFINE_RXPRT_EVENT(xprtrdma_remove); DEFINE_RXPRT_EVENT(xprtrdma_reinsert); DEFINE_RXPRT_EVENT(xprtrdma_reconnect); -DEFINE_RXPRT_EVENT(xprtrdma_inject_dsc); +DEFINE_RXPRT_EVENT(xprtrdma_op_inject_dsc); +DEFINE_RXPRT_EVENT(xprtrdma_op_close); +DEFINE_RXPRT_EVENT(xprtrdma_op_connect); TRACE_EVENT(xprtrdma_qp_event, TP_PROTO( @@ -834,7 +836,7 @@ TRACE_EVENT(xprtrdma_decode_seg, ** Allocation/release of rpcrdma_reqs and rpcrdma_reps **/ -TRACE_EVENT(xprtrdma_allocate, +TRACE_EVENT(xprtrdma_op_allocate, TP_PROTO( const struct rpc_task *task, const struct rpcrdma_req *req @@ -864,7 +866,7 @@ TRACE_EVENT(xprtrdma_allocate, ) ); -TRACE_EVENT(xprtrdma_rpc_done, +TRACE_EVENT(xprtrdma_op_free, TP_PROTO( const struct rpc_task *task, const struct rpcrdma_req *req -- cgit v1.2.3 From 53b2c1cb9b3cd901a200ddbbf08c77eabf1ab3e9 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 19 Dec 2018 11:00:06 -0500 Subject: xprtrdma: Trace mapping, alloc, and dereg failures These are rare, but can be helpful at tracking down DMAR and other problems. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 136 +++++++++++++++++++++++++++++++++++++++++ 1 file changed, 136 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index 3d068bba4532..ce528d5942c5 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -10,6 +10,7 @@ #if !defined(_TRACE_RPCRDMA_H) || defined(TRACE_HEADER_MULTI_READ) #define _TRACE_RPCRDMA_H +#include #include #include @@ -663,12 +664,147 @@ DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_fastreg); DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li); DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li_wake); +TRACE_EVENT(xprtrdma_frwr_alloc, + TP_PROTO( + const struct rpcrdma_mr *mr, + int rc + ), + + TP_ARGS(mr, rc), + + TP_STRUCT__entry( + __field(const void *, mr) + __field(int, rc) + ), + + TP_fast_assign( + __entry->mr = mr; + __entry->rc = rc; + ), + + TP_printk("mr=%p: rc=%d", + __entry->mr, __entry->rc + ) +); + +TRACE_EVENT(xprtrdma_frwr_dereg, + TP_PROTO( + const struct rpcrdma_mr *mr, + int rc + ), + + TP_ARGS(mr, rc), + + TP_STRUCT__entry( + __field(const void *, mr) + __field(u32, handle) + __field(u32, length) + __field(u64, offset) + __field(u32, dir) + __field(int, rc) + ), + + TP_fast_assign( + __entry->mr = mr; + __entry->handle = mr->mr_handle; + __entry->length = mr->mr_length; + __entry->offset = mr->mr_offset; + __entry->dir = mr->mr_dir; + __entry->rc = rc; + ), + + TP_printk("mr=%p %u@0x%016llx:0x%08x (%s): rc=%d", + __entry->mr, __entry->length, + (unsigned long long)__entry->offset, __entry->handle, + xprtrdma_show_direction(__entry->dir), + __entry->rc + ) +); + +TRACE_EVENT(xprtrdma_frwr_sgerr, + TP_PROTO( + const struct rpcrdma_mr *mr, + int sg_nents + ), + + TP_ARGS(mr, sg_nents), + + TP_STRUCT__entry( + __field(const void *, mr) + __field(u64, addr) + __field(u32, dir) + __field(int, nents) + ), + + TP_fast_assign( + __entry->mr = mr; + __entry->addr = mr->mr_sg->dma_address; + __entry->dir = mr->mr_dir; + __entry->nents = sg_nents; + ), + + TP_printk("mr=%p dma addr=0x%llx (%s) sg_nents=%d", + __entry->mr, __entry->addr, + xprtrdma_show_direction(__entry->dir), + __entry->nents + ) +); + +TRACE_EVENT(xprtrdma_frwr_maperr, + TP_PROTO( + const struct rpcrdma_mr *mr, + int num_mapped + ), + + TP_ARGS(mr, num_mapped), + + TP_STRUCT__entry( + __field(const void *, mr) + __field(u64, addr) + __field(u32, dir) + __field(int, num_mapped) + __field(int, nents) + ), + + TP_fast_assign( + __entry->mr = mr; + __entry->addr = mr->mr_sg->dma_address; + __entry->dir = mr->mr_dir; + __entry->num_mapped = num_mapped; + __entry->nents = mr->mr_nents; + ), + + TP_printk("mr=%p dma addr=0x%llx (%s) nents=%d of %d", + __entry->mr, __entry->addr, + xprtrdma_show_direction(__entry->dir), + __entry->num_mapped, __entry->nents + ) +); + DEFINE_MR_EVENT(localinv); DEFINE_MR_EVENT(map); DEFINE_MR_EVENT(unmap); DEFINE_MR_EVENT(remoteinv); DEFINE_MR_EVENT(recycle); +TRACE_EVENT(xprtrdma_dma_maperr, + TP_PROTO( + u64 addr + ), + + TP_ARGS(addr), + + TP_STRUCT__entry( + __field(u64, addr) + ), + + TP_fast_assign( + __entry->addr = addr; + ), + + TP_printk("dma addr=0x%llx\n", __entry->addr) +); + /** ** Reply events **/ -- cgit v1.2.3 From dc5820bd21d84ee34770b0a1e2fca9378f8f7456 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Wed, 19 Dec 2018 11:00:16 -0500 Subject: SUNRPC: Simplify defining common RPC trace events Clean up, no functional change is expected. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/sunrpc.h | 172 +++++++++++++++++------------------------- 1 file changed, 69 insertions(+), 103 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 28e384186c35..88bda93e8f90 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -16,40 +16,6 @@ DECLARE_EVENT_CLASS(rpc_task_status, - TP_PROTO(struct rpc_task *task), - - TP_ARGS(task), - - TP_STRUCT__entry( - __field(unsigned int, task_id) - __field(unsigned int, client_id) - __field(int, status) - ), - - TP_fast_assign( - __entry->task_id = task->tk_pid; - __entry->client_id = task->tk_client->cl_clid; - __entry->status = task->tk_status; - ), - - TP_printk("task:%u@%u status=%d", - __entry->task_id, __entry->client_id, - __entry->status) -); - -DEFINE_EVENT(rpc_task_status, rpc_call_status, - TP_PROTO(struct rpc_task *task), - - TP_ARGS(task) -); - -DEFINE_EVENT(rpc_task_status, rpc_bind_status, - TP_PROTO(struct rpc_task *task), - - TP_ARGS(task) -); - -TRACE_EVENT(rpc_connect_status, TP_PROTO(const struct rpc_task *task), TP_ARGS(task), @@ -70,6 +36,16 @@ TRACE_EVENT(rpc_connect_status, __entry->task_id, __entry->client_id, __entry->status) ); +#define DEFINE_RPC_STATUS_EVENT(name) \ + DEFINE_EVENT(rpc_task_status, rpc_##name##_status, \ + TP_PROTO( \ + const struct rpc_task *task \ + ), \ + TP_ARGS(task)) + +DEFINE_RPC_STATUS_EVENT(call); +DEFINE_RPC_STATUS_EVENT(bind); +DEFINE_RPC_STATUS_EVENT(connect); TRACE_EVENT(rpc_request, TP_PROTO(const struct rpc_task *task), @@ -134,30 +110,17 @@ DECLARE_EVENT_CLASS(rpc_task_running, __entry->action ) ); +#define DEFINE_RPC_RUNNING_EVENT(name) \ + DEFINE_EVENT(rpc_task_running, rpc_task_##name, \ + TP_PROTO( \ + const struct rpc_task *task, \ + const void *action \ + ), \ + TP_ARGS(task, action)) -DEFINE_EVENT(rpc_task_running, rpc_task_begin, - - TP_PROTO(const struct rpc_task *task, const void *action), - - TP_ARGS(task, action) - -); - -DEFINE_EVENT(rpc_task_running, rpc_task_run_action, - - TP_PROTO(const struct rpc_task *task, const void *action), - - TP_ARGS(task, action) - -); - -DEFINE_EVENT(rpc_task_running, rpc_task_complete, - - TP_PROTO(const struct rpc_task *task, const void *action), - - TP_ARGS(task, action) - -); +DEFINE_RPC_RUNNING_EVENT(begin); +DEFINE_RPC_RUNNING_EVENT(run_action); +DEFINE_RPC_RUNNING_EVENT(complete); DECLARE_EVENT_CLASS(rpc_task_queued, @@ -195,22 +158,16 @@ DECLARE_EVENT_CLASS(rpc_task_queued, __get_str(q_name) ) ); +#define DEFINE_RPC_QUEUED_EVENT(name) \ + DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \ + TP_PROTO( \ + const struct rpc_task *task, \ + const struct rpc_wait_queue *q \ + ), \ + TP_ARGS(task, q)) -DEFINE_EVENT(rpc_task_queued, rpc_task_sleep, - - TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q), - - TP_ARGS(task, q) - -); - -DEFINE_EVENT(rpc_task_queued, rpc_task_wakeup, - - TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q), - - TP_ARGS(task, q) - -); +DEFINE_RPC_QUEUED_EVENT(sleep); +DEFINE_RPC_QUEUED_EVENT(wakeup); TRACE_EVENT(rpc_stats_latency, @@ -410,7 +367,11 @@ DEFINE_RPC_SOCKET_EVENT(rpc_socket_close); DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown); DECLARE_EVENT_CLASS(rpc_xprt_event, - TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status), + TP_PROTO( + const struct rpc_xprt *xprt, + __be32 xid, + int status + ), TP_ARGS(xprt, xid, status), @@ -432,22 +393,19 @@ DECLARE_EVENT_CLASS(rpc_xprt_event, __get_str(port), __entry->xid, __entry->status) ); +#define DEFINE_RPC_XPRT_EVENT(name) \ + DEFINE_EVENT(rpc_xprt_event, xprt_##name, \ + TP_PROTO( \ + const struct rpc_xprt *xprt, \ + __be32 xid, \ + int status \ + ), \ + TP_ARGS(xprt, xid, status)) -DEFINE_EVENT(rpc_xprt_event, xprt_timer, - TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status), - TP_ARGS(xprt, xid, status)); - -DEFINE_EVENT(rpc_xprt_event, xprt_lookup_rqst, - TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status), - TP_ARGS(xprt, xid, status)); - -DEFINE_EVENT(rpc_xprt_event, xprt_transmit, - TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status), - TP_ARGS(xprt, xid, status)); - -DEFINE_EVENT(rpc_xprt_event, xprt_complete_rqst, - TP_PROTO(struct rpc_xprt *xprt, __be32 xid, int status), - TP_ARGS(xprt, xid, status)); +DEFINE_RPC_XPRT_EVENT(timer); +DEFINE_RPC_XPRT_EVENT(lookup_rqst); +DEFINE_RPC_XPRT_EVENT(transmit); +DEFINE_RPC_XPRT_EVENT(complete_rqst); TRACE_EVENT(xprt_ping, TP_PROTO(const struct rpc_xprt *xprt, int status), @@ -587,7 +545,9 @@ TRACE_EVENT(svc_process, DECLARE_EVENT_CLASS(svc_rqst_event, - TP_PROTO(struct svc_rqst *rqst), + TP_PROTO( + const struct svc_rqst *rqst + ), TP_ARGS(rqst), @@ -607,14 +567,15 @@ DECLARE_EVENT_CLASS(svc_rqst_event, __get_str(addr), __entry->xid, show_rqstp_flags(__entry->flags)) ); +#define DEFINE_SVC_RQST_EVENT(name) \ + DEFINE_EVENT(svc_rqst_event, svc_##name, \ + TP_PROTO( \ + const struct svc_rqst *rqst \ + ), \ + TP_ARGS(rqst)) -DEFINE_EVENT(svc_rqst_event, svc_defer, - TP_PROTO(struct svc_rqst *rqst), - TP_ARGS(rqst)); - -DEFINE_EVENT(svc_rqst_event, svc_drop, - TP_PROTO(struct svc_rqst *rqst), - TP_ARGS(rqst)); +DEFINE_SVC_RQST_EVENT(defer); +DEFINE_SVC_RQST_EVENT(drop); DECLARE_EVENT_CLASS(svc_rqst_status, @@ -801,7 +762,9 @@ TRACE_EVENT(svc_stats_latency, ); DECLARE_EVENT_CLASS(svc_deferred_event, - TP_PROTO(struct svc_deferred_req *dr), + TP_PROTO( + const struct svc_deferred_req *dr + ), TP_ARGS(dr), @@ -818,13 +781,16 @@ DECLARE_EVENT_CLASS(svc_deferred_event, TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid) ); +#define DEFINE_SVC_DEFERRED_EVENT(name) \ + DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \ + TP_PROTO( \ + const struct svc_deferred_req *dr \ + ), \ + TP_ARGS(dr)) + +DEFINE_SVC_DEFERRED_EVENT(drop); +DEFINE_SVC_DEFERRED_EVENT(revisit); -DEFINE_EVENT(svc_deferred_event, svc_drop_deferred, - TP_PROTO(struct svc_deferred_req *dr), - TP_ARGS(dr)); -DEFINE_EVENT(svc_deferred_event, svc_revisit_deferred, - TP_PROTO(struct svc_deferred_req *dr), - TP_ARGS(dr)); #endif /* _TRACE_SUNRPC_H */ #include -- cgit v1.2.3 From 07e10308ee5da8e6132e0b737ece1c99dd651fb6 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Fri, 7 Dec 2018 11:11:44 -0500 Subject: xprtrdma: Prevent leak of rpcrdma_rep objects If a reply has been processed but the RPC is later retransmitted anyway, the req->rl_reply field still contains the only pointer to the old rpcrdma rep. When the next reply comes in, the reply handler will stomp on the rl_reply field, leaking the old rep. A trace event is added to capture such leaks. This problem seems to be worsened by the restructuring of the RPC Call path in v4.20. Fully addressing this issue will require at least a re-architecture of the disconnect logic, which is not appropriate during -rc. Signed-off-by: Chuck Lever Signed-off-by: Anna Schumaker --- include/trace/events/rpcrdma.h | 28 ++++++++++++++++++++++++++++ 1 file changed, 28 insertions(+) (limited to 'include/trace') diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h index ce528d5942c5..399b1aedc927 100644 --- a/include/trace/events/rpcrdma.h +++ b/include/trace/events/rpcrdma.h @@ -1065,6 +1065,34 @@ TRACE_EVENT(xprtrdma_cb_setup, DEFINE_CB_EVENT(xprtrdma_cb_call); DEFINE_CB_EVENT(xprtrdma_cb_reply); +TRACE_EVENT(xprtrdma_leaked_rep, + TP_PROTO( + const struct rpc_rqst *rqst, + const struct rpcrdma_rep *rep + ), + + TP_ARGS(rqst, rep), + + TP_STRUCT__entry( + __field(unsigned int, task_id) + __field(unsigned int, client_id) + __field(u32, xid) + __field(const void *, rep) + ), + + TP_fast_assign( + __entry->task_id = rqst->rq_task->tk_pid; + __entry->client_id = rqst->rq_task->tk_client->cl_clid; + __entry->xid = be32_to_cpu(rqst->rq_xid); + __entry->rep = rep; + ), + + TP_printk("task:%u@%u xid=0x%08x rep=%p", + __entry->task_id, __entry->client_id, __entry->xid, + __entry->rep + ) +); + /** ** Server-side RPC/RDMA events **/ -- cgit v1.2.3