sunrpc: add new tracepoints in xprt handling code

...so we can keep track of when calls are sent and replies received.

Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>

2 files changed, 15 insertions, 2 deletions

diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index 56e4e150e80e..1b2e5e616cae 100644
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -49,6 +49,8 @@
 #include <linux/sunrpc/metrics.h>
 #include <linux/sunrpc/bc_xprt.h>
 
+#include <trace/events/sunrpc.h>
+
 #include "sunrpc.h"
 
 /*
@@ -772,11 +774,14 @@ struct rpc_rqst *xprt_lookup_rqst(struct rpc_xprt *xprt, __be32 xid)
         struct rpc_rqst *entry;
 
         list_for_each_entry(entry, &xprt->recv, rq_list)
-                if (entry->rq_xid == xid)
+                if (entry->rq_xid == xid) {
+                        trace_xprt_lookup_rqst(xprt, xid, 0);
                         return entry;
+                }
 
         dprintk("RPC:       xprt_lookup_rqst did not find xid %08x\n",
                         ntohl(xid));
+        trace_xprt_lookup_rqst(xprt, xid, -ENOENT);
         xprt->stat.bad_xids++;
         return NULL;
 }
@@ -810,6 +815,7 @@ void xprt_complete_rqst(struct rpc_task *task, int copied)
 
         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++;
         req->rq_rtt = ktime_sub(ktime_get(), req->rq_xtime);
@@ -926,6 +932,7 @@ void xprt_transmit(struct rpc_task *task)
 
         req->rq_xtime = ktime_get();
         status = xprt->ops->send_request(task);
+        trace_xprt_transmit(xprt, req->rq_xid, status);
         if (status != 0) {
                 task->tk_status = status;
                 return;
diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 3b305ab17afe..b63e26272dc2 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -1454,12 +1454,15 @@ static void xs_tcp_data_ready(struct sock *sk)
         struct rpc_xprt *xprt;
         read_descriptor_t rd_desc;
         int read;
+        unsigned long total = 0;
 
         dprintk("RPC:       xs_tcp_data_ready...\n");
 
         read_lock_bh(&sk->sk_callback_lock);
-        if (!(xprt = xprt_from_sock(sk)))
+        if (!(xprt = xprt_from_sock(sk))) {
+                read = 0;
                 goto out;
+        }
         /* Any data means we had a useful conversation, so
          * the we don't need to delay the next reconnect
          */
@@ -1471,8 +1474,11 @@ static void xs_tcp_data_ready(struct sock *sk)
         do {
                 rd_desc.count = 65536;
                 read = tcp_read_sock(sk, &rd_desc, xs_tcp_data_recv);
+                if (read > 0)
+                        total += read;
         } while (read > 0);
 out:
+        trace_xs_tcp_data_ready(xprt, read, total);
         read_unlock_bh(&sk->sk_callback_lock);
 }