]> www.infradead.org Git - users/hch/misc.git/commit
sunrpc: add info about xprt queue times to svc_xprt_dequeue tracepoint
authorJeff Layton <jlayton@kernel.org>
Fri, 11 Apr 2025 14:22:14 +0000 (10:22 -0400)
committerChuck Lever <chuck.lever@oracle.com>
Sun, 11 May 2025 23:48:26 +0000 (19:48 -0400)
commit18c64378ad85ef00e70f196793ee8901a8aa2fa1
treed36fa9fff02668cd7bcbe7d1dd18557b97e6c25a
parent8c4aae5582cf7901655988809ad94a6f6f2bce63
sunrpc: add info about xprt queue times to svc_xprt_dequeue tracepoint

I've been looking at a problem where we see increased RPC timeouts in
clients when the nfs_layout_flexfiles dataserver_timeo value is tuned
very low (6s). This is necessary to ensure quick failover to a different
mirror if a server goes down, but it causes a lot more major RPC timeouts.

Ultimately, the problem is server-side however. It's sometimes doesn't
respond to connection attempts. My theory is that the interrupt handler
runs when a connection comes in, the xprt ends up being enqueued, but it
takes a significant amount of time for the nfsd thread to pick it up.

Currently, the svc_xprt_dequeue tracepoint displays "wakeup-us". This is
the time between the wake_up() call, and the thread dequeueing the xprt.
If no thread was woken, or the thread ended up picking up a different
xprt than intended, then this value won't tell us how long the xprt was
waiting.

Add a new xpt_qtime field to struct svc_xprt and set it in
svc_xprt_enqueue(). When the dequeue tracepoint fires, also store the
time that the xprt sat on the queue in total. Display it as "qtime-us".

Signed-off-by: Jeff Layton <jlayton@kernel.org>
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
include/linux/sunrpc/svc_xprt.h
include/trace/events/sunrpc.h
net/sunrpc/svc_xprt.c