xprtrdma: Instrument allocation/release of rpcrdma_req/rep objects

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>

diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h
index 1e5ae57a4f0d8bf54f62168328348915456a9e84..50ed3f8bf534a6ceb627f9afeb70cff7cd0b51a5 100644 (file)
--- a/include/trace/events/rpcrdma.h
+++ b/include/trace/events/rpcrdma.h
@@ -783,6 +783,73 @@ TRACE_EVENT(xprtrdma_decode_seg,
        )
 );
 
+/**
+ ** Allocation/release of rpcrdma_reqs and rpcrdma_reps
+ **/
+
+TRACE_EVENT(xprtrdma_allocate,
+       TP_PROTO(
+               const struct rpc_task *task,
+               const struct rpcrdma_req *req
+       ),
+
+       TP_ARGS(task, req),
+
+       TP_STRUCT__entry(
+               __field(unsigned int, task_id)
+               __field(unsigned int, client_id)
+               __field(const void *, req)
+               __field(const void *, rep)
+               __field(size_t, callsize)
+               __field(size_t, rcvsize)
+       ),
+
+       TP_fast_assign(
+               __entry->task_id = task->tk_pid;
+               __entry->client_id = task->tk_client->cl_clid;
+               __entry->req = req;
+               __entry->rep = req ? req->rl_reply : NULL;
+               __entry->callsize = task->tk_rqstp->rq_callsize;
+               __entry->rcvsize = task->tk_rqstp->rq_rcvsize;
+       ),
+
+       TP_printk("task:%u@%u req=%p rep=%p (%zu, %zu)",
+               __entry->task_id, __entry->client_id,
+               __entry->req, __entry->rep,
+               __entry->callsize, __entry->rcvsize
+       )
+);
+
+TRACE_EVENT(xprtrdma_rpc_done,
+       TP_PROTO(
+               const struct rpc_task *task,
+               const struct rpcrdma_req *req
+       ),
+
+       TP_ARGS(task, req),
+
+       TP_STRUCT__entry(
+               __field(unsigned int, task_id)
+               __field(unsigned int, client_id)
+               __field(const void *, req)
+               __field(const void *, rep)
+       ),
+
+       TP_fast_assign(
+               __entry->task_id = task->tk_pid;
+               __entry->client_id = task->tk_client->cl_clid;
+               __entry->req = req;
+               __entry->rep = req->rl_reply;
+       ),
+
+       TP_printk("task:%u@%u req=%p rep=%p",
+               __entry->task_id, __entry->client_id,
+               __entry->req, __entry->rep
+       )
+);
+
+DEFINE_RXPRT_EVENT(xprtrdma_noreps);
+
 /**
  ** Callback events
  **/

diff --git a/net/sunrpc/xprtrdma/transport.c b/net/sunrpc/xprtrdma/transport.c
index 25d1160dc0850558e26f42838c4ac08dadbf05b7..b90179af88bf4d489062a492871ae55245bd32c2 100644 (file)
--- a/net/sunrpc/xprtrdma/transport.c
+++ b/net/sunrpc/xprtrdma/transport.c
@@ -640,7 +640,7 @@ xprt_rdma_allocate(struct rpc_task *task)
 
        req = rpcrdma_buffer_get(&r_xprt->rx_buf);
        if (req == NULL)
-               return -ENOMEM;
+               goto out_get;
 
        flags = RPCRDMA_DEF_GFP;
        if (RPC_IS_SWAPPER(task))
@@ -653,19 +653,18 @@ xprt_rdma_allocate(struct rpc_task *task)
        if (!rpcrdma_get_recvbuf(r_xprt, req, rqst->rq_rcvsize, flags))
                goto out_fail;
 
-       dprintk("RPC: %5u %s: send size = %zd, recv size = %zd, req = %p\n",
-               task->tk_pid, __func__, rqst->rq_callsize,
-               rqst->rq_rcvsize, req);
-
        req->rl_cpu = smp_processor_id();
        req->rl_connect_cookie = 0;     /* our reserved value */
        rpcrdma_set_xprtdata(rqst, req);
        rqst->rq_buffer = req->rl_sendbuf->rg_base;
        rqst->rq_rbuffer = req->rl_recvbuf->rg_base;
+       trace_xprtrdma_allocate(task, req);
        return 0;
 
 out_fail:
        rpcrdma_buffer_put(req);
+out_get:
+       trace_xprtrdma_allocate(task, NULL);
        return -ENOMEM;
 }
 
@@ -682,10 +681,9 @@ xprt_rdma_free(struct rpc_task *task)
        struct rpcrdma_xprt *r_xprt = rpcx_to_rdmax(rqst->rq_xprt);
        struct rpcrdma_req *req = rpcr_to_rdmar(rqst);
 
-       dprintk("RPC:       %s: called on 0x%p\n", __func__, req->rl_reply);
-
        if (test_bit(RPCRDMA_REQ_F_PENDING, &req->rl_flags))
                rpcrdma_release_rqst(r_xprt, req);
+       trace_xprtrdma_rpc_done(task, req);
        rpcrdma_buffer_put(req);
 }
 

diff --git a/net/sunrpc/xprtrdma/verbs.c b/net/sunrpc/xprtrdma/verbs.c
index fb81d3a4b0b34a82cb821a9c5c8554f149208e14..57e1139d85bc18bdad270c8baac4143c6d14f042 100644 (file)
--- a/net/sunrpc/xprtrdma/verbs.c
+++ b/net/sunrpc/xprtrdma/verbs.c
@@ -1385,11 +1385,11 @@ rpcrdma_buffer_get(struct rpcrdma_buffer *buffers)
        req = rpcrdma_buffer_get_req_locked(buffers);
        req->rl_reply = rpcrdma_buffer_get_rep(buffers);
        spin_unlock(&buffers->rb_lock);
+
        return req;
 
 out_reqbuf:
        spin_unlock(&buffers->rb_lock);
-       pr_warn("RPC:       %s: out of request buffers\n", __func__);
        return NULL;
 }
 
@@ -1612,7 +1612,7 @@ rpcrdma_ep_post_extra_recv(struct rpcrdma_xprt *r_xprt, unsigned int count)
 
 out_reqbuf:
        spin_unlock(&buffers->rb_lock);
-       pr_warn("%s: no extra receive buffers\n", __func__);
+       trace_xprtrdma_noreps(r_xprt);
        return -ENOMEM;
 
 out_rc: