SUNRPC: Add tracepoints for dropped and deferred requests

Dropping and/or deferring requests has an impact on performance. Let's
make sure we can trace those events.

Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>

2 files changed, 65 insertions, 0 deletions

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index b014207a95a8..8a707f8a41c3 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -473,6 +473,39 @@ TRACE_EVENT(svc_recv,
                         show_rqstp_flags(__entry->flags))
 );
 
+DECLARE_EVENT_CLASS(svc_rqst_event,
+
+        TP_PROTO(struct svc_rqst *rqst),
+
+        TP_ARGS(rqst),
+
+        TP_STRUCT__entry(
+                __field(__be32, xid)
+                __field(unsigned long, flags)
+                __dynamic_array(unsigned char, addr, rqst->rq_addrlen)
+        ),
+
+        TP_fast_assign(
+                __entry->xid = rqst->rq_xid;
+                __entry->flags = rqst->rq_flags;
+                memcpy(__get_dynamic_array(addr),
+                        &rqst->rq_addr, rqst->rq_addrlen);
+        ),
+
+        TP_printk("addr=%pIScp rq_xid=0x%x flags=%s",
+                (struct sockaddr *)__get_dynamic_array(addr),
+                be32_to_cpu(__entry->xid),
+                show_rqstp_flags(__entry->flags))
+);
+
+DEFINE_EVENT(svc_rqst_event, svc_defer,
+        TP_PROTO(struct svc_rqst *rqst),
+        TP_ARGS(rqst));
+
+DEFINE_EVENT(svc_rqst_event, svc_drop,
+        TP_PROTO(struct svc_rqst *rqst),
+        TP_ARGS(rqst));
+
 DECLARE_EVENT_CLASS(svc_rqst_status,
 
         TP_PROTO(struct svc_rqst *rqst, int status),
@@ -636,6 +669,34 @@ TRACE_EVENT(svc_handle_xprt,
                         (struct sockaddr *)__get_dynamic_array(addr) : NULL,
                 __entry->len, show_svc_xprt_flags(__entry->flags))
 );
+
+
+DECLARE_EVENT_CLASS(svc_deferred_event,
+        TP_PROTO(struct svc_deferred_req *dr),
+
+        TP_ARGS(dr),
+
+        TP_STRUCT__entry(
+                __field(__be32, xid)
+                __dynamic_array(unsigned char, addr, dr->addrlen)
+        ),
+
+        TP_fast_assign(
+                __entry->xid = *(__be32 *)(dr->args + (dr->xprt_hlen>>2));
+                memcpy(__get_dynamic_array(addr), &dr->addr, dr->addrlen);
+        ),
+
+        TP_printk("addr=%pIScp xid=0x%x",
+                (struct sockaddr *)__get_dynamic_array(addr),
+                be32_to_cpu(__entry->xid))
+);
+
+DEFINE_EVENT(svc_deferred_event, svc_drop_deferred,
+        TP_PROTO(struct svc_deferred_req *dr),
+        TP_ARGS(dr));
+DEFINE_EVENT(svc_deferred_event, svc_revisit_deferred,
+        TP_PROTO(struct svc_deferred_req *dr),
+        TP_ARGS(dr));
 #endif /* _TRACE_SUNRPC_H */
 
 #include <trace/define_trace.h>
diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index 4d2189a562af..e7082a4aeb56 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -875,6 +875,7 @@ EXPORT_SYMBOL_GPL(svc_recv);
  */
 void svc_drop(struct svc_rqst *rqstp)
 {
+        trace_svc_drop(rqstp);
         dprintk("svc: xprt %p dropped request\n", rqstp->rq_xprt);
         svc_xprt_release(rqstp);
 }
@@ -1152,6 +1153,7 @@ static void svc_revisit(struct cache_deferred_req *dreq, int too_many)
                 spin_unlock(&xprt->xpt_lock);
                 dprintk("revisit canceled\n");
                 svc_xprt_put(xprt);
+                trace_svc_drop_deferred(dr);
                 kfree(dr);
                 return;
         }
@@ -1209,6 +1211,7 @@ static struct cache_deferred_req *svc_defer(struct cache_req *req)
         set_bit(RQ_DROPME, &rqstp->rq_flags);
 
         dr->handle.revisit = svc_revisit;
+        trace_svc_defer(rqstp);
         return &dr->handle;
 }
 
@@ -1249,6 +1252,7 @@ static struct svc_deferred_req *svc_deferred_dequeue(struct svc_xprt *xprt)
                                 struct svc_deferred_req,
                                 handle.recent);
                 list_del_init(&dr->handle.recent);
+                trace_svc_revisit_deferred(dr);
         } else
                 clear_bit(XPT_DEFERRED, &xprt->xpt_flags);
         spin_unlock(&xprt->xpt_lock);