SUNRPC: Hoist trace_xprtrdma_op_allocate into generic code

Introduce a tracepoint in call_allocate that reports the exact
sizes in the RPC buffer allocation request and the status of the
result. This helps catch problems with XDR buffer provisioning,
and replaces transport-specific debugging instrumentation.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>
This commit is contained in:
Chuck Lever 2020-07-08 16:09:11 -04:00 committed by Anna Schumaker
parent e4378a0fdd
commit 06e234c613
5 changed files with 31 additions and 36 deletions

View File

@ -1191,36 +1191,6 @@ TRACE_EVENT(xprtrdma_decode_seg,
** Allocation/release of rpcrdma_reqs and rpcrdma_reps
**/
TRACE_EVENT(xprtrdma_op_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(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->callsize = task->tk_rqstp->rq_callsize;
__entry->rcvsize = task->tk_rqstp->rq_rcvsize;
),
TP_printk("task:%u@%u req=%p (%zu, %zu)",
__entry->task_id, __entry->client_id,
__entry->req, __entry->callsize, __entry->rcvsize
)
);
TRACE_EVENT(xprtrdma_op_free,
TP_PROTO(
const struct rpc_task *task,

View File

@ -517,6 +517,36 @@ DEFINE_RPC_REPLY_EVENT(stale_creds);
DEFINE_RPC_REPLY_EVENT(bad_creds);
DEFINE_RPC_REPLY_EVENT(auth_tooweak);
TRACE_EVENT(rpc_buf_alloc,
TP_PROTO(
const struct rpc_task *task,
int status
),
TP_ARGS(task, status),
TP_STRUCT__entry(
__field(unsigned int, task_id)
__field(unsigned int, client_id)
__field(size_t, callsize)
__field(size_t, recvsize)
__field(int, status)
),
TP_fast_assign(
__entry->task_id = task->tk_pid;
__entry->client_id = task->tk_client->cl_clid;
__entry->callsize = task->tk_rqstp->rq_callsize;
__entry->recvsize = task->tk_rqstp->rq_rcvsize;
__entry->status = status;
),
TP_printk("task:%u@%u callsize=%zu recvsize=%zu status=%d",
__entry->task_id, __entry->client_id,
__entry->callsize, __entry->recvsize, __entry->status
)
);
TRACE_EVENT(rpc_call_rpcerror,
TP_PROTO(
const struct rpc_task *task,

View File

@ -1823,6 +1823,7 @@ call_allocate(struct rpc_task *task)
req->rq_rcvsize <<= 2;
status = xprt->ops->buf_alloc(task);
trace_rpc_buf_alloc(task, status);
xprt_inject_disconnect(xprt);
if (status == 0)
return;
@ -1831,8 +1832,6 @@ call_allocate(struct rpc_task *task)
return;
}
dprintk("RPC: %5u rpc_buffer allocation failed\n", task->tk_pid);
if (RPC_IS_ASYNC(task) || !fatal_signal_pending(current)) {
task->tk_action = call_allocate;
rpc_delay(task, HZ>>4);

View File

@ -1036,8 +1036,6 @@ int rpc_malloc(struct rpc_task *task)
return -ENOMEM;
buf->len = size;
dprintk("RPC: %5u allocated buffer of size %zu at %p\n",
task->tk_pid, size, buf);
rqst->rq_buffer = buf->data;
rqst->rq_rbuffer = (char *)rqst->rq_buffer + rqst->rq_callsize;
return 0;

View File

@ -586,11 +586,9 @@ xprt_rdma_allocate(struct rpc_task *task)
rqst->rq_buffer = rdmab_data(req->rl_sendbuf);
rqst->rq_rbuffer = rdmab_data(req->rl_recvbuf);
trace_xprtrdma_op_allocate(task, req);
return 0;
out_fail:
trace_xprtrdma_op_allocate(task, NULL);
return -ENOMEM;
}