sunrpc: Report per-RPC execution stats

Introduce a mechanism to report the server-side execution latency of
each RPC. The goal is to enable user space to filter the trace
record for latency outliers, build histograms, etc.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>

2 files changed, 22 insertions, 0 deletions

diff --git a/include/linux/sunrpc/svc.h b/include/linux/sunrpc/svc.h
index 786ae2255f05..3bd7504066e1 100644
--- a/include/linux/sunrpc/svc.h
+++ b/include/linux/sunrpc/svc.h
@@ -283,6 +283,7 @@ struct svc_rqst {
         int                     rq_reserved;    /* space on socket outq
                                                  * reserved for this request
                                                  */
+        ktime_t                 rq_stime;       /* start time */
 
         struct cache_req        rq_chandle;     /* handle passed to caches for 
                                                  * request delaying 
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 5a8157c04900..1b383f71ccd7 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -705,6 +705,27 @@ TRACE_EVENT(svc_handle_xprt,
                 __entry->len, show_svc_xprt_flags(__entry->flags))
 );
 
+TRACE_EVENT(svc_stats_latency,
+        TP_PROTO(const struct svc_rqst *rqst),
+
+        TP_ARGS(rqst),
+
+        TP_STRUCT__entry(
+                __field(u32, xid)
+                __field(unsigned long, execute)
+                __string(addr, rqst->rq_xprt->xpt_remotebuf)
+        ),
+
+        TP_fast_assign(
+                __entry->xid = be32_to_cpu(rqst->rq_xid);
+                __entry->execute = ktime_to_us(ktime_sub(ktime_get(),
+                                                         rqst->rq_stime));
+                __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
+        ),
+
+        TP_printk("addr=%s xid=0x%08x execute-us=%lu",
+                __get_str(addr), __entry->xid, __entry->execute)
+);
 
 DECLARE_EVENT_CLASS(svc_deferred_event,
         TP_PROTO(struct svc_deferred_req *dr),