sunrpc: Add rpc_request static trace point

Display information about the RPC procedure being requested in the
trace log. This sometimes critical information cannot always be
derived from other RPC trace entries.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 82e5057c7707377707c497f75f308a6cf428fd02..d7c6dc739f6650246d50e865678f861c3facb7dc 100644 (file)
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -70,6 +70,36 @@ TRACE_EVENT(rpc_connect_status,
                __entry->status)
 );
 
+TRACE_EVENT(rpc_request,
+       TP_PROTO(const struct rpc_task *task),
+
+       TP_ARGS(task),
+
+       TP_STRUCT__entry(
+               __field(unsigned int, task_id)
+               __field(unsigned int, client_id)
+               __field(int, version)
+               __field(bool, async)
+               __string(progname, task->tk_client->cl_program->name)
+               __string(procname, rpc_proc_name(task))
+       ),
+
+       TP_fast_assign(
+               __entry->task_id = task->tk_pid;
+               __entry->client_id = task->tk_client->cl_clid;
+               __entry->version = task->tk_client->cl_vers;
+               __entry->async = RPC_IS_ASYNC(task);
+               __assign_str(progname, task->tk_client->cl_program->name)
+               __assign_str(procname, rpc_proc_name(task))
+       ),
+
+       TP_printk("task:%u@%u %sv%d %s (%ssync)",
+               __entry->task_id, __entry->client_id,
+               __get_str(progname), __entry->version,
+               __get_str(procname), __entry->async ? "a": ""
+               )
+);
+
 DECLARE_EVENT_CLASS(rpc_task_running,
 
        TP_PROTO(const struct rpc_clnt *clnt, const struct rpc_task *task, const void *action),

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index d25b077d326de8d517c04ff23b266ce79236d210..a801da812f8660246df1ac0949cf66c99e991907 100644 (file)
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -1491,7 +1491,6 @@ rpc_restart_call(struct rpc_task *task)
 }
 EXPORT_SYMBOL_GPL(rpc_restart_call);
 
-#if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
 const char
 *rpc_proc_name(const struct rpc_task *task)
 {
@@ -1505,7 +1504,6 @@ const char
        } else
                return "no proc";
 }
-#endif
 
 /*
  * 0.  Initial state
@@ -1519,6 +1517,7 @@ call_start(struct rpc_task *task)
        struct rpc_clnt *clnt = task->tk_client;
        int idx = task->tk_msg.rpc_proc->p_statidx;
 
+       trace_rpc_request(task);
        dprintk("RPC: %5u call_start %s%d proc %s (%s)\n", task->tk_pid,
                        clnt->cl_program->name, clnt->cl_vers,
                        rpc_proc_name(task),