| Message ID | 158284985994.38468.11081309957716392757.stgit@seurat29.1015granger.net (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | NFS/RDMA server patches maybe for v5.7 | expand |
Just to note this patch hits client paths too. > Begin forwarded message: > > From: Chuck Lever <chuck.lever@oracle.com> > Subject: [PATCH v1 05/16] svcrdma: Create a generic tracing class for displaying xdr_buf layout > Date: February 27, 2020 at 4:30:59 PM PST > To: bfields@fieldses.org > Cc: linux-nfs@vger.kernel.org, linux-rdma@vger.kernel.org > > This class can be used to create trace points in either the RPC > client or RPC server paths. It simply displays the length of each > part of an xdr_buf, which is useful to determine that the transport > and XDR codecs are operating correctly. > > Signed-off-by: Chuck Lever <chuck.lever@oracle.com> > --- > include/trace/events/sunrpc.h | 43 +++++++++++++++++++++++++++++++++++++++++ > net/sunrpc/svc_xprt.c | 6 +++++- > net/sunrpc/xprt.c | 4 ++-- > 3 files changed, 50 insertions(+), 3 deletions(-) > > diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h > index ee993575d2fa..1577223add43 100644 > --- a/include/trace/events/sunrpc.h > +++ b/include/trace/events/sunrpc.h > @@ -14,6 +14,49 @@ > #include <linux/net.h> > #include <linux/tracepoint.h> > > +DECLARE_EVENT_CLASS(xdr_buf_class, > + TP_PROTO( > + const struct xdr_buf *xdr > + ), > + > + TP_ARGS(xdr), > + > + TP_STRUCT__entry( > + __field(const void *, head_base) > + __field(size_t, head_len) > + __field(const void *, tail_base) > + __field(size_t, tail_len) > + __field(unsigned int, page_len) > + __field(unsigned int, msg_len) > + ), > + > + TP_fast_assign( > + __entry->head_base = xdr->head[0].iov_base; > + __entry->head_len = xdr->head[0].iov_len; > + __entry->tail_base = xdr->tail[0].iov_base; > + __entry->tail_len = xdr->tail[0].iov_len; > + __entry->page_len = xdr->page_len; > + __entry->msg_len = xdr->len; > + ), > + > + TP_printk("head=[%p,%zu] page=%u tail=[%p,%zu] len=%u", > + __entry->head_base, __entry->head_len, __entry->page_len, > + __entry->tail_base, __entry->tail_len, __entry->msg_len > + ) > +); > + > +#define DEFINE_XDRBUF_EVENT(name) \ > + DEFINE_EVENT(xdr_buf_class, name, \ > + TP_PROTO( \ > + const struct xdr_buf *xdr \ > + ), \ > + TP_ARGS(xdr)) > + > +DEFINE_XDRBUF_EVENT(xprt_sendto); > +DEFINE_XDRBUF_EVENT(xprt_recvfrom); > +DEFINE_XDRBUF_EVENT(svc_recvfrom); > +DEFINE_XDRBUF_EVENT(svc_sendto); > + > TRACE_DEFINE_ENUM(RPC_AUTH_OK); > TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED); > TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED); > diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c > index de3c077733a7..081564449e98 100644 > --- a/net/sunrpc/svc_xprt.c > +++ b/net/sunrpc/svc_xprt.c > @@ -802,6 +802,8 @@ static int svc_handle_xprt(struct svc_rqst *rqstp, struct svc_xprt *xprt) > len = svc_deferred_recv(rqstp); > else > len = xprt->xpt_ops->xpo_recvfrom(rqstp); > + if (len > 0) > + trace_svc_recvfrom(&rqstp->rq_arg); > rqstp->rq_stime = ktime_get(); > rqstp->rq_reserved = serv->sv_max_mesg; > atomic_add(rqstp->rq_reserved, &xprt->xpt_reserved); > @@ -912,8 +914,10 @@ int svc_send(struct svc_rqst *rqstp) > if (test_bit(XPT_DEAD, &xprt->xpt_flags) > || test_bit(XPT_CLOSE, &xprt->xpt_flags)) > len = -ENOTCONN; > - else > + else { > + trace_svc_sendto(xb); > len = xprt->xpt_ops->xpo_sendto(rqstp); > + } > mutex_unlock(&xprt->xpt_mutex); > trace_svc_send(rqstp, len); > svc_xprt_release(rqstp); > diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c > index 1aafe8d3f3f4..30989d9b61a0 100644 > --- a/net/sunrpc/xprt.c > +++ b/net/sunrpc/xprt.c > @@ -1117,9 +1117,8 @@ void xprt_complete_rqst(struct rpc_task *task, int copied) > struct rpc_rqst *req = task->tk_rqstp; > struct rpc_xprt *xprt = req->rq_xprt; > > - dprintk("RPC: %5u xid %08x complete (%d bytes received)\n", > - task->tk_pid, ntohl(req->rq_xid), copied); > trace_xprt_complete_rqst(xprt, req->rq_xid, copied); > + trace_xprt_recvfrom(&req->rq_rcv_buf); > > xprt->stat.recvs++; > > @@ -1462,6 +1461,7 @@ xprt_request_transmit(struct rpc_rqst *req, struct rpc_task *snd_task) > */ > req->rq_ntrans++; > > + trace_xprt_sendto(&req->rq_snd_buf); > connect_cookie = xprt->connect_cookie; > status = xprt->ops->send_request(req); > if (status != 0) { > -- Chuck Lever
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index ee993575d2fa..1577223add43 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -14,6 +14,49 @@ #include <linux/net.h> #include <linux/tracepoint.h> +DECLARE_EVENT_CLASS(xdr_buf_class, + TP_PROTO( + const struct xdr_buf *xdr + ), + + TP_ARGS(xdr), + + TP_STRUCT__entry( + __field(const void *, head_base) + __field(size_t, head_len) + __field(const void *, tail_base) + __field(size_t, tail_len) + __field(unsigned int, page_len) + __field(unsigned int, msg_len) + ), + + TP_fast_assign( + __entry->head_base = xdr->head[0].iov_base; + __entry->head_len = xdr->head[0].iov_len; + __entry->tail_base = xdr->tail[0].iov_base; + __entry->tail_len = xdr->tail[0].iov_len; + __entry->page_len = xdr->page_len; + __entry->msg_len = xdr->len; + ), + + TP_printk("head=[%p,%zu] page=%u tail=[%p,%zu] len=%u", + __entry->head_base, __entry->head_len, __entry->page_len, + __entry->tail_base, __entry->tail_len, __entry->msg_len + ) +); + +#define DEFINE_XDRBUF_EVENT(name) \ + DEFINE_EVENT(xdr_buf_class, name, \ + TP_PROTO( \ + const struct xdr_buf *xdr \ + ), \ + TP_ARGS(xdr)) + +DEFINE_XDRBUF_EVENT(xprt_sendto); +DEFINE_XDRBUF_EVENT(xprt_recvfrom); +DEFINE_XDRBUF_EVENT(svc_recvfrom); +DEFINE_XDRBUF_EVENT(svc_sendto); + TRACE_DEFINE_ENUM(RPC_AUTH_OK); TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED); TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED); diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c index de3c077733a7..081564449e98 100644 --- a/net/sunrpc/svc_xprt.c +++ b/net/sunrpc/svc_xprt.c @@ -802,6 +802,8 @@ static int svc_handle_xprt(struct svc_rqst *rqstp, struct svc_xprt *xprt) len = svc_deferred_recv(rqstp); else len = xprt->xpt_ops->xpo_recvfrom(rqstp); + if (len > 0) + trace_svc_recvfrom(&rqstp->rq_arg); rqstp->rq_stime = ktime_get(); rqstp->rq_reserved = serv->sv_max_mesg; atomic_add(rqstp->rq_reserved, &xprt->xpt_reserved); @@ -912,8 +914,10 @@ int svc_send(struct svc_rqst *rqstp) if (test_bit(XPT_DEAD, &xprt->xpt_flags) || test_bit(XPT_CLOSE, &xprt->xpt_flags)) len = -ENOTCONN; - else + else { + trace_svc_sendto(xb); len = xprt->xpt_ops->xpo_sendto(rqstp); + } mutex_unlock(&xprt->xpt_mutex); trace_svc_send(rqstp, len); svc_xprt_release(rqstp); diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c index 1aafe8d3f3f4..30989d9b61a0 100644 --- a/net/sunrpc/xprt.c +++ b/net/sunrpc/xprt.c @@ -1117,9 +1117,8 @@ void xprt_complete_rqst(struct rpc_task *task, int copied) struct rpc_rqst *req = task->tk_rqstp; struct rpc_xprt *xprt = req->rq_xprt; - dprintk("RPC: %5u xid %08x complete (%d bytes received)\n", - task->tk_pid, ntohl(req->rq_xid), copied); trace_xprt_complete_rqst(xprt, req->rq_xid, copied); + trace_xprt_recvfrom(&req->rq_rcv_buf); xprt->stat.recvs++; @@ -1462,6 +1461,7 @@ xprt_request_transmit(struct rpc_rqst *req, struct rpc_task *snd_task) */ req->rq_ntrans++; + trace_xprt_sendto(&req->rq_snd_buf); connect_cookie = xprt->connect_cookie; status = xprt->ops->send_request(req); if (status != 0) {
This class can be used to create trace points in either the RPC client or RPC server paths. It simply displays the length of each part of an xdr_buf, which is useful to determine that the transport and XDR codecs are operating correctly. Signed-off-by: Chuck Lever <chuck.lever@oracle.com> --- include/trace/events/sunrpc.h | 43 +++++++++++++++++++++++++++++++++++++++++ net/sunrpc/svc_xprt.c | 6 +++++- net/sunrpc/xprt.c | 4 ++-- 3 files changed, 50 insertions(+), 3 deletions(-)