This is a note to let you know that I've just added the patch titled
SUNRPC: Trace calls to .rpc_call_done
to the 5.10-stable tree which can be found at:
http://www.kernel.org/git/?p=linux/kernel/git/stable/stable-queue.git;a=summary
The filename of the patch is:
sunrpc-trace-calls-to-.rpc_call_done.patch
and it can be found in the queue-5.10 subdirectory.
If you, or anyone else, feels it should not be added to the stable tree,
please let <stable@xxxxxxxxxxxxxxx> know about it.
commit 17a42584c433bc8992be0fba2753ae6ea8c54689
Author: Chuck Lever <chuck.lever@xxxxxxxxxx>
Date: Sat Oct 16 18:02:57 2021 -0400
SUNRPC: Trace calls to .rpc_call_done
[ Upstream commit b40887e10dcacc5e8ae3c1a99dcba20877c4831b ]
Introduce a single tracepoint that can replace simple dprintk call
sites in upper layer "rpc_call_done" callbacks. Example:
kworker/u24:2-1254 [001] 771.026677: rpc_stats_latency: task:00000001@00000002 xid=0x16a6f3c0 rpcbindv2 GETPORT backlog=446 rtt=101 execute=555
kworker/u24:2-1254 [001] 771.026677: rpc_task_call_done: task:00000001@00000002 flags=ASYNC|DYNAMIC|SOFT|SOFTCONN|SENT runstate=RUNNING|ACTIVE status=0 action=rpcb_getport_done
kworker/u24:2-1254 [001] 771.026678: rpcb_setport: task:00000001@00000002 status=0 port=20048
Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
Signed-off-by: Trond Myklebust <trond.myklebust@xxxxxxxxxxxxxxx>
Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
Signed-off-by: Sasha Levin <sashal@xxxxxxxxxx>
diff --git a/fs/lockd/clntproc.c b/fs/lockd/clntproc.c
index b11f2afa84f1f..99fffc9cb9585 100644
--- a/fs/lockd/clntproc.c
+++ b/fs/lockd/clntproc.c
@@ -794,9 +794,6 @@ static void nlmclnt_cancel_callback(struct rpc_task *task, void *data)
goto retry_cancel;
}
- dprintk("lockd: cancel status %u (task %u)\n",
- status, task->tk_pid);
-
switch (status) {
case NLM_LCK_GRANTED:
case NLM_LCK_DENIED_GRACE_PERIOD:
diff --git a/fs/lockd/svc4proc.c b/fs/lockd/svc4proc.c
index e10ae2c41279e..176b468a61c75 100644
--- a/fs/lockd/svc4proc.c
+++ b/fs/lockd/svc4proc.c
@@ -269,8 +269,6 @@ nlm4svc_proc_granted(struct svc_rqst *rqstp)
*/
static void nlm4svc_callback_exit(struct rpc_task *task, void *data)
{
- dprintk("lockd: %5u callback returned %d\n", task->tk_pid,
- -task->tk_status);
}
static void nlm4svc_callback_release(void *data)
diff --git a/fs/lockd/svcproc.c b/fs/lockd/svcproc.c
index 99696d3f6dd66..4dc1b40a489a2 100644
--- a/fs/lockd/svcproc.c
+++ b/fs/lockd/svcproc.c
@@ -301,8 +301,6 @@ nlmsvc_proc_granted(struct svc_rqst *rqstp)
*/
static void nlmsvc_callback_exit(struct rpc_task *task, void *data)
{
- dprintk("lockd: %5u callback returned %d\n", task->tk_pid,
- -task->tk_status);
}
void nlmsvc_release_call(struct nlm_rqst *call)
diff --git a/fs/nfs/filelayout/filelayout.c b/fs/nfs/filelayout/filelayout.c
index 45eec08ec904f..2ed8b6885b091 100644
--- a/fs/nfs/filelayout/filelayout.c
+++ b/fs/nfs/filelayout/filelayout.c
@@ -293,8 +293,6 @@ static void filelayout_read_call_done(struct rpc_task *task, void *data)
{
struct nfs_pgio_header *hdr = data;
- dprintk("--> %s task->tk_status %d\n", __func__, task->tk_status);
-
if (test_bit(NFS_IOHDR_REDO, &hdr->flags) &&
task->tk_status == 0) {
nfs41_sequence_done(task, &hdr->res.seq_res);
diff --git a/fs/nfs/flexfilelayout/flexfilelayout.c b/fs/nfs/flexfilelayout/flexfilelayout.c
index f2ae271fe7ec7..a263bfec4244d 100644
--- a/fs/nfs/flexfilelayout/flexfilelayout.c
+++ b/fs/nfs/flexfilelayout/flexfilelayout.c
@@ -1419,8 +1419,6 @@ static void ff_layout_read_call_done(struct rpc_task *task, void *data)
{
struct nfs_pgio_header *hdr = data;
- dprintk("--> %s task->tk_status %d\n", __func__, task->tk_status);
-
if (test_bit(NFS_IOHDR_REDO, &hdr->flags) &&
task->tk_status == 0) {
nfs4_sequence_done(task, &hdr->res.seq_res);
diff --git a/fs/nfs/pagelist.c b/fs/nfs/pagelist.c
index 17fef6eb490c5..d79a3b6cb0701 100644
--- a/fs/nfs/pagelist.c
+++ b/fs/nfs/pagelist.c
@@ -870,9 +870,6 @@ static void nfs_pgio_result(struct rpc_task *task, void *calldata)
struct nfs_pgio_header *hdr = calldata;
struct inode *inode = hdr->inode;
- dprintk("NFS: %s: %5u, (status %d)\n", __func__,
- task->tk_pid, task->tk_status);
-
if (hdr->rw_ops->rw_done(task, hdr, inode) != 0)
return;
if (task->tk_status < 0)
diff --git a/fs/nfs/write.c b/fs/nfs/write.c
index 4cf0606919794..2bde35921f2b2 100644
--- a/fs/nfs/write.c
+++ b/fs/nfs/write.c
@@ -1809,9 +1809,6 @@ static void nfs_commit_done(struct rpc_task *task, void *calldata)
{
struct nfs_commit_data *data = calldata;
- dprintk("NFS: %5u nfs_commit_done (status %d)\n",
- task->tk_pid, task->tk_status);
-
/* Call the NFS version-specific code */
NFS_PROTO(data->inode)->commit_done(task, data);
trace_nfs_commit_done(task, data);
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index fce071f39f51f..56e4a57d25382 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -394,6 +394,7 @@ DEFINE_RPC_RUNNING_EVENT(complete);
DEFINE_RPC_RUNNING_EVENT(timeout);
DEFINE_RPC_RUNNING_EVENT(signalled);
DEFINE_RPC_RUNNING_EVENT(end);
+DEFINE_RPC_RUNNING_EVENT(call_done);
DECLARE_EVENT_CLASS(rpc_task_queued,
diff --git a/net/sunrpc/sched.c b/net/sunrpc/sched.c
index a00890962e115..a4c9d410eb8d5 100644
--- a/net/sunrpc/sched.c
+++ b/net/sunrpc/sched.c
@@ -821,6 +821,7 @@ void rpc_exit_task(struct rpc_task *task)
else if (task->tk_client)
rpc_count_iostats(task, task->tk_client->cl_metrics);
if (task->tk_ops->rpc_call_done != NULL) {
+ trace_rpc_task_call_done(task, task->tk_ops->rpc_call_done);
task->tk_ops->rpc_call_done(task, task->tk_calldata);
if (task->tk_action != NULL) {
/* Always release the RPC slot and buffer memory */
