From 55f5088c22cc83dbc64394abfbf76cd1ff5e7cd0 Mon Sep 17 00:00:00 2001 From: Chuck Lever Date: Tue, 27 Mar 2018 10:52:27 -0400 Subject: svc: Report xprt dequeue latency Record the time between when a rqstp is enqueued on a transport and when it is dequeued. This includes how long the rqstp waits on the queue and how long it takes the kernel scheduler to wake a nfsd thread to service it. The svc_xprt_dequeue trace point is altered to include the number of microseconds between xprt_enqueue and xprt_dequeue. Signed-off-by: Chuck Lever Signed-off-by: J. Bruce Fields --- net/sunrpc/svc_xprt.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'net/sunrpc') diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c index a7425da14f5b..5185efb9027b 100644 --- a/net/sunrpc/svc_xprt.c +++ b/net/sunrpc/svc_xprt.c @@ -409,6 +409,7 @@ void svc_xprt_do_enqueue(struct svc_xprt *xprt) if (test_and_set_bit(RQ_BUSY, &rqstp->rq_flags)) continue; atomic_long_inc(&pool->sp_stats.threads_woken); + rqstp->rq_qtime = ktime_get(); wake_up_process(rqstp->rq_task); goto out_unlock; } @@ -530,7 +531,6 @@ void svc_wake_up(struct svc_serv *serv) if (test_bit(RQ_BUSY, &rqstp->rq_flags)) continue; rcu_read_unlock(); - dprintk("svc: daemon %p woken up.\n", rqstp); wake_up_process(rqstp->rq_task); trace_svc_wake_up(rqstp->rq_task->pid); return; @@ -726,7 +726,7 @@ out_found: rqstp->rq_chandle.thread_wait = 5*HZ; else rqstp->rq_chandle.thread_wait = 1*HZ; - trace_svc_xprt_dequeue(rqstp->rq_xprt); + trace_svc_xprt_dequeue(rqstp); return rqstp->rq_xprt; } -- cgit v1.2.3-59-g8ed1b