svcrdma: Create a generic tracing class for displaying xdr_buf layout
authorChuck Lever <chuck.lever@oracle.com>
Mon, 2 Mar 2020 20:01:08 +0000 (15:01 -0500)
committerChuck Lever <chuck.lever@oracle.com>
Mon, 16 Mar 2020 16:04:32 +0000 (12:04 -0400)
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
net/sunrpc/clnt.c
net/sunrpc/svc_xprt.c
net/sunrpc/xprt.c

index ee993575d2fad63a2e87357863512eb2febc6009..1577223add4389bd3f30b06e15ed578ad771ba2c 100644 (file)
 #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);
index 7324b21f923e6816399168a1ad9ef3dd9fb362bc..07992d3e8703fc6d4796f824c832c267fe59c81b 100644 (file)
@@ -2509,6 +2509,7 @@ call_decode(struct rpc_task *task)
                goto out;
 
        req->rq_rcv_buf.len = req->rq_private_buf.len;
+       trace_xprt_recvfrom(&req->rq_rcv_buf);
 
        /* Check that the softirq receive buffer is valid */
        WARN_ON(memcmp(&req->rq_rcv_buf, &req->rq_private_buf,
index de3c077733a7a6ea48de4f20ce2aa6654607b9e8..d53259346235ce3449aea35317ebe2ce38b2657e 100644 (file)
@@ -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);
@@ -905,6 +907,7 @@ int svc_send(struct svc_rqst *rqstp)
        xb->len = xb->head[0].iov_len +
                xb->page_len +
                xb->tail[0].iov_len;
+       trace_svc_sendto(xb);
 
        /* Grab mutex to serialize outgoing data. */
        mutex_lock(&xprt->xpt_mutex);
index 1aafe8d3f3f431ce251820ed47058a9203739ef8..493a30a296fcf2464b2549cbd76215c4bdcce8d3 100644 (file)
@@ -1117,8 +1117,6 @@ 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);
 
        xprt->stat.recvs++;
@@ -1462,6 +1460,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) {