SUNRPC: introduce per-task RPC iostats

Account for various things that occur while an RPC task is executed.
Separate timers for RPC round trip and RPC execution time show how
long RPC requests wait in queue before being sent.  Eventually these
will be accumulated at xprt_release time in one place where they can
be viewed from userland.

Test plan:
Compile kernel with CONFIG_NFS enabled.

Signed-off-by: Chuck Lever <cel@netapp.com>
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>

diff --git a/include/linux/sunrpc/sched.h b/include/linux/sunrpc/sched.h
index 6c23f73a799a0760649ccc89eefd34d1f50ac272..45a64ae963ee7db920e5eb628607c980d4b18484 100644 (file)
--- a/include/linux/sunrpc/sched.h
+++ b/include/linux/sunrpc/sched.h
@@ -86,6 +86,12 @@ struct rpc_task {
                struct work_struct      tk_work;        /* Async task work queue */
                struct rpc_wait         tk_wait;        /* RPC wait */
        } u;
+
+       unsigned short          tk_timeouts;    /* maj timeouts */
+       size_t                  tk_bytes_sent;  /* total bytes sent */
+       unsigned long           tk_start;       /* RPC task init timestamp */
+       long                    tk_rtt;         /* round-trip time (jiffies) */
+
 #ifdef RPC_DEBUG
        unsigned short          tk_pid;         /* debugging aid */
 #endif

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index cad7efe2cb225bd73d0e020004b4255ce99140ba..84eb5b4565fc8f5a5646365df0e1d32d79624a70 100644 (file)
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -996,6 +996,8 @@ call_timeout(struct rpc_task *task)
        }
 
        dprintk("RPC: %4d call_timeout (major)\n", task->tk_pid);
+       task->tk_timeouts++;
+
        if (RPC_IS_SOFT(task)) {
                printk(KERN_NOTICE "%s: server %s not responding, timed out\n",
                                clnt->cl_protname, clnt->cl_server);

diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c
index aa0449dcd8e521d53448c8c1a2f98a8f84c27786..cd51b54683323cad7988c2b835714c2bb738c567 100644 (file)
--- a/net/sunrpc/sched.c
+++ b/net/sunrpc/sched.c
@@ -817,6 +817,9 @@ void rpc_init_task(struct rpc_task *task, struct rpc_clnt *clnt, int flags, cons
 
        BUG_ON(task->tk_ops == NULL);
 
+       /* starting timestamp */
+       task->tk_start = jiffies;
+
        dprintk("RPC: %4d new task procpid %d\n", task->tk_pid,
                                current->pid);
 }

diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index 93a0a3ca0d5ff90e88b6714bdcd031e2c0b59abd..c6241976a6eebafcb233d5cde9a65b0392087acf 100644 (file)
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -648,6 +648,8 @@ void xprt_complete_rqst(struct rpc_task *task, int copied)
                        task->tk_pid, ntohl(req->rq_xid), copied);
 
        task->tk_xprt->stat.recvs++;
+       task->tk_rtt = (long)jiffies - req->rq_xtime;
+
        list_del_init(&req->rq_list);
        req->rq_received = req->rq_private_buf.len = copied;
        rpc_wake_up_task(task);

diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 6766b7f1ecf97ccda9c36138c83b30f750e63db0..4b4e7dfdff14538dcb172d66ab68ef44b44bdd11 100644 (file)
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -382,6 +382,7 @@ static int xs_tcp_send_request(struct rpc_task *task)
                /* If we've sent the entire packet, immediately
                 * reset the count of bytes sent. */
                req->rq_bytes_sent += status;
+               task->tk_bytes_sent += status;
                if (likely(req->rq_bytes_sent >= req->rq_slen)) {
                        req->rq_bytes_sent = 0;
                        return 0;