Commit ef759a2e authored by Chuck Lever's avatar Chuck Lever Committed by Trond Myklebust

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: default avatarChuck Lever <cel@netapp.com>
Signed-off-by: default avatarTrond Myklebust <Trond.Myklebust@netapp.com>
parent 262ca07d
...@@ -86,6 +86,12 @@ struct rpc_task { ...@@ -86,6 +86,12 @@ struct rpc_task {
struct work_struct tk_work; /* Async task work queue */ struct work_struct tk_work; /* Async task work queue */
struct rpc_wait tk_wait; /* RPC wait */ struct rpc_wait tk_wait; /* RPC wait */
} u; } 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 #ifdef RPC_DEBUG
unsigned short tk_pid; /* debugging aid */ unsigned short tk_pid; /* debugging aid */
#endif #endif
......
...@@ -996,6 +996,8 @@ call_timeout(struct rpc_task *task) ...@@ -996,6 +996,8 @@ call_timeout(struct rpc_task *task)
} }
dprintk("RPC: %4d call_timeout (major)\n", task->tk_pid); dprintk("RPC: %4d call_timeout (major)\n", task->tk_pid);
task->tk_timeouts++;
if (RPC_IS_SOFT(task)) { if (RPC_IS_SOFT(task)) {
printk(KERN_NOTICE "%s: server %s not responding, timed out\n", printk(KERN_NOTICE "%s: server %s not responding, timed out\n",
clnt->cl_protname, clnt->cl_server); clnt->cl_protname, clnt->cl_server);
......
...@@ -817,6 +817,9 @@ void rpc_init_task(struct rpc_task *task, struct rpc_clnt *clnt, int flags, cons ...@@ -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); BUG_ON(task->tk_ops == NULL);
/* starting timestamp */
task->tk_start = jiffies;
dprintk("RPC: %4d new task procpid %d\n", task->tk_pid, dprintk("RPC: %4d new task procpid %d\n", task->tk_pid,
current->pid); current->pid);
} }
......
...@@ -648,6 +648,8 @@ void xprt_complete_rqst(struct rpc_task *task, int copied) ...@@ -648,6 +648,8 @@ void xprt_complete_rqst(struct rpc_task *task, int copied)
task->tk_pid, ntohl(req->rq_xid), copied); task->tk_pid, ntohl(req->rq_xid), copied);
task->tk_xprt->stat.recvs++; task->tk_xprt->stat.recvs++;
task->tk_rtt = (long)jiffies - req->rq_xtime;
list_del_init(&req->rq_list); list_del_init(&req->rq_list);
req->rq_received = req->rq_private_buf.len = copied; req->rq_received = req->rq_private_buf.len = copied;
rpc_wake_up_task(task); rpc_wake_up_task(task);
......
...@@ -382,6 +382,7 @@ static int xs_tcp_send_request(struct rpc_task *task) ...@@ -382,6 +382,7 @@ static int xs_tcp_send_request(struct rpc_task *task)
/* If we've sent the entire packet, immediately /* If we've sent the entire packet, immediately
* reset the count of bytes sent. */ * reset the count of bytes sent. */
req->rq_bytes_sent += status; req->rq_bytes_sent += status;
task->tk_bytes_sent += status;
if (likely(req->rq_bytes_sent >= req->rq_slen)) { if (likely(req->rq_bytes_sent >= req->rq_slen)) {
req->rq_bytes_sent = 0; req->rq_bytes_sent = 0;
return 0; return 0;
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment