- Recover some instruction count because I'm about to introduce a few xdr_inline_decode call sites - Replace dprintk() call sites with trace points - Reduce the hot path so it fits in fewer cachelines I've also renamed it rpc_decode_header() to match everything else in the RPC client. Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx> --- include/trace/events/sunrpc.h | 52 ++++++++++ net/sunrpc/clnt.c | 223 ++++++++++++++++++----------------------- 2 files changed, 148 insertions(+), 127 deletions(-) diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 2b3f9d1..0531fc4 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -241,6 +241,58 @@ TP_ARGS(task)) DEFINE_RPC_FAILURE(callhdr); +DEFINE_RPC_FAILURE(verifier); + +DECLARE_EVENT_CLASS(rpc_reply_event, + + TP_PROTO( + const struct rpc_task *task + ), + + TP_ARGS(task), + + TP_STRUCT__entry( + __field(unsigned int, task_id) + __field(unsigned int, client_id) + __field(u32, xid) + __string(progname, task->tk_client->cl_program->name) + __field(u32, version) + __string(procname, rpc_proc_name(task)) + __string(servername, task->tk_xprt->servername) + ), + + TP_fast_assign( + __entry->task_id = task->tk_pid; + __entry->client_id = task->tk_client->cl_clid; + __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); + __assign_str(progname, task->tk_client->cl_program->name) + __entry->version = task->tk_client->cl_vers; + __assign_str(procname, rpc_proc_name(task)) + __assign_str(servername, task->tk_xprt->servername) + ), + + TP_printk("task:%u@%d server=%s xid=0x%08x %sv%d %s", + __entry->task_id, __entry->client_id, __get_str(servername), + __entry->xid, __get_str(progname), __entry->version, + __get_str(procname)) +) + +#define DEFINE_RPC_REPLY_EVENT(name) \ + DEFINE_EVENT(rpc_reply_event, rpc_##name, \ + TP_PROTO( \ + const struct rpc_task *task \ + ), \ + TP_ARGS(task)) + +DEFINE_RPC_REPLY_EVENT(prog_unavail); +DEFINE_RPC_REPLY_EVENT(prog_mismatch); +DEFINE_RPC_REPLY_EVENT(proc_unavail); +DEFINE_RPC_REPLY_EVENT(garbage_args); +DEFINE_RPC_REPLY_EVENT(unparsable); +DEFINE_RPC_REPLY_EVENT(mismatch); +DEFINE_RPC_REPLY_EVENT(stale_creds); +DEFINE_RPC_REPLY_EVENT(bad_creds); +DEFINE_RPC_REPLY_EVENT(auth_tooweak); TRACE_EVENT(rpc_stats_latency, diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c index 83549c4..2461b18 100644 --- a/net/sunrpc/clnt.c +++ b/net/sunrpc/clnt.c @@ -79,7 +79,7 @@ static int rpc_encode_header(struct rpc_task *task, struct xdr_stream *xdr); -static __be32 *rpc_verify_header(struct rpc_task *task); +static __be32 *rpc_decode_header(struct rpc_task *task); static int rpc_ping(struct rpc_clnt *clnt); static void rpc_register_client(struct rpc_clnt *clnt) @@ -2292,7 +2292,7 @@ void rpc_force_rebind(struct rpc_clnt *clnt) goto out_retry; } - p = rpc_verify_header(task); + p = rpc_decode_header(task); if (IS_ERR(p)) { if (p == ERR_PTR(-EAGAIN)) goto out_retry; @@ -2308,7 +2308,7 @@ void rpc_force_rebind(struct rpc_clnt *clnt) return; out_retry: task->tk_status = 0; - /* Note: rpc_verify_header() may have freed the RPC slot */ + /* Note: rpc_decode_header() may have freed the RPC slot */ if (task->tk_rqstp == req) { xdr_free_bvec(&req->rq_rcv_buf); req->rq_reply_bytes_recvd = req->rq_rcv_buf.len = 0; @@ -2347,164 +2347,133 @@ void rpc_force_rebind(struct rpc_clnt *clnt) return error; } -static __be32 * -rpc_verify_header(struct rpc_task *task) +static noinline __be32 * +rpc_decode_header(struct rpc_task *task) { struct rpc_clnt *clnt = task->tk_client; struct kvec *iov = &task->tk_rqstp->rq_rcv_buf.head[0]; int len = task->tk_rqstp->rq_rcv_buf.len >> 2; __be32 *p = iov->iov_base; - u32 n; int error = -EACCES; - if ((task->tk_rqstp->rq_rcv_buf.len & 3) != 0) { - /* RFC-1014 says that the representation of XDR data must be a - * multiple of four bytes - * - if it isn't pointer subtraction in the NFS client may give - * undefined results - */ - dprintk("RPC: %5u %s: XDR representation not a multiple of" - " 4 bytes: 0x%x\n", task->tk_pid, __func__, - task->tk_rqstp->rq_rcv_buf.len); - error = -EIO; - goto out_err; - } + /* RFC-1014 says that the representation of XDR data must be a + * multiple of four bytes + * - if it isn't pointer subtraction in the NFS client may give + * undefined results + */ + if (task->tk_rqstp->rq_rcv_buf.len & 3) + goto out_badlen; if ((len -= 3) < 0) - goto out_overflow; + goto out_unparsable; - p += 1; /* skip XID */ - if ((n = ntohl(*p++)) != RPC_REPLY) { - dprintk("RPC: %5u %s: not an RPC reply: %x\n", - task->tk_pid, __func__, n); - error = -EIO; - goto out_garbage; - } + p++; /* skip XID */ + if (*p++ != rpc_reply) + goto out_unparsable; + if (*p++ != rpc_msg_accepted) + goto out_msg_denied; - if ((n = ntohl(*p++)) != RPC_MSG_ACCEPTED) { - if (--len < 0) - goto out_overflow; - switch ((n = ntohl(*p++))) { - case RPC_AUTH_ERROR: - break; - case RPC_MISMATCH: - dprintk("RPC: %5u %s: RPC call version mismatch!\n", - task->tk_pid, __func__); - error = -EPROTONOSUPPORT; - goto out_err; - default: - dprintk("RPC: %5u %s: RPC call rejected, " - "unknown error: %x\n", - task->tk_pid, __func__, n); - error = -EIO; - goto out_err; - } - if (--len < 0) - goto out_overflow; - switch ((n = ntohl(*p++))) { - case RPC_AUTH_REJECTEDCRED: - case RPC_AUTH_REJECTEDVERF: - case RPCSEC_GSS_CREDPROBLEM: - case RPCSEC_GSS_CTXPROBLEM: - if (!task->tk_cred_retry) - break; - task->tk_cred_retry--; - dprintk("RPC: %5u %s: retry stale creds\n", - task->tk_pid, __func__); - rpcauth_invalcred(task); - /* Ensure we obtain a new XID! */ - xprt_release(task); - task->tk_action = call_reserve; - goto out_retry; - case RPC_AUTH_BADCRED: - case RPC_AUTH_BADVERF: - /* possibly garbled cred/verf? */ - if (!task->tk_garb_retry) - break; - task->tk_garb_retry--; - dprintk("RPC: %5u %s: retry garbled creds\n", - task->tk_pid, __func__); - task->tk_action = call_encode; - goto out_retry; - case RPC_AUTH_TOOWEAK: - printk(KERN_NOTICE "RPC: server %s requires stronger " - "authentication.\n", - task->tk_xprt->servername); - break; - default: - dprintk("RPC: %5u %s: unknown auth error: %x\n", - task->tk_pid, __func__, n); - error = -EIO; - } - dprintk("RPC: %5u %s: call rejected %d\n", - task->tk_pid, __func__, n); - goto out_err; - } p = rpcauth_checkverf(task, p); - if (IS_ERR(p)) { - error = PTR_ERR(p); - dprintk("RPC: %5u %s: auth check failed with %d\n", - task->tk_pid, __func__, error); - goto out_garbage; /* bad verifier, retry */ - } + if (IS_ERR(p)) + goto out_verifier; + len = p - (__be32 *)iov->iov_base - 1; if (len < 0) - goto out_overflow; - switch ((n = ntohl(*p++))) { - case RPC_SUCCESS: + goto out_unparsable; + switch (*p++) { + case rpc_success: return p; - case RPC_PROG_UNAVAIL: - dprintk("RPC: %5u %s: program %u is unsupported " - "by server %s\n", task->tk_pid, __func__, - (unsigned int)clnt->cl_prog, - task->tk_xprt->servername); + case rpc_prog_unavail: + trace_rpc_prog_unavail(task); error = -EPFNOSUPPORT; goto out_err; - case RPC_PROG_MISMATCH: - dprintk("RPC: %5u %s: program %u, version %u unsupported " - "by server %s\n", task->tk_pid, __func__, - (unsigned int)clnt->cl_prog, - (unsigned int)clnt->cl_vers, - task->tk_xprt->servername); + case rpc_prog_mismatch: + trace_rpc_prog_mismatch(task); error = -EPROTONOSUPPORT; goto out_err; - case RPC_PROC_UNAVAIL: - dprintk("RPC: %5u %s: proc %s unsupported by program %u, " - "version %u on server %s\n", - task->tk_pid, __func__, - rpc_proc_name(task), - clnt->cl_prog, clnt->cl_vers, - task->tk_xprt->servername); + case rpc_proc_unavail: + trace_rpc_proc_unavail(task); error = -EOPNOTSUPP; goto out_err; - case RPC_GARBAGE_ARGS: - dprintk("RPC: %5u %s: server saw garbage\n", - task->tk_pid, __func__); - break; /* retry */ + case rpc_garbage_args: + trace_rpc_garbage_args(task); + break; default: - dprintk("RPC: %5u %s: server accept status: %x\n", - task->tk_pid, __func__, n); - /* Also retry */ + trace_rpc_unparsable(task); } out_garbage: clnt->cl_stats->rpcgarbage++; if (task->tk_garb_retry) { task->tk_garb_retry--; - dprintk("RPC: %5u %s: retrying\n", - task->tk_pid, __func__); task->tk_action = call_encode; -out_retry: return ERR_PTR(-EAGAIN); } out_err: rpc_exit(task, error); - dprintk("RPC: %5u %s: call failed with error %d\n", task->tk_pid, - __func__, error); return ERR_PTR(error); -out_overflow: - dprintk("RPC: %5u %s: server reply was truncated.\n", task->tk_pid, - __func__); + +out_badlen: + trace_rpc_unparsable(task); + error = -EIO; + goto out_err; + +out_unparsable: + trace_rpc_unparsable(task); + error = -EIO; goto out_garbage; + +out_verifier: + trace_rpc_bad_verifier(task); + error = PTR_ERR(p); + goto out_garbage; + +out_msg_denied: + switch (*p++) { + case rpc_auth_error: + break; + case rpc_mismatch: + trace_rpc_mismatch(task); + error = -EPROTONOSUPPORT; + goto out_err; + default: + trace_rpc_unparsable(task); + error = -EIO; + goto out_err; + } + + switch (*p++) { + case rpc_autherr_rejectedcred: + case rpc_autherr_rejectedverf: + case rpcsec_gsserr_credproblem: + case rpcsec_gsserr_ctxproblem: + if (!task->tk_cred_retry) + break; + task->tk_cred_retry--; + trace_rpc_stale_creds(task); + rpcauth_invalcred(task); + /* Ensure we obtain a new XID! */ + xprt_release(task); + task->tk_action = call_reserve; + return ERR_PTR(-EAGAIN); + case rpc_autherr_badcred: + case rpc_autherr_badverf: + /* possibly garbled cred/verf? */ + if (!task->tk_garb_retry) + break; + task->tk_garb_retry--; + trace_rpc_bad_creds(task); + task->tk_action = call_encode; + return ERR_PTR(-EAGAIN); + case rpc_autherr_tooweak: + trace_rpc_auth_tooweak(task); + pr_warn("RPC: server %s requires stronger authentication.\n", + task->tk_xprt->servername); + break; + default: + trace_rpc_unparsable(task); + error = -EIO; + } + goto out_err; } static void rpcproc_encode_null(struct rpc_rqst *rqstp, struct xdr_stream *xdr,