[PATCH v2 0/6] Ensure RPC_TASK_NORTO is disabled for select operations

[PATCH v2 0/6] Ensure RPC_TASK_NORTO is disabled for select operations

[Chuck Lever]

This is a set of patches I've been toying with to get better
responsiveness from a client when a transport remains connected but
the server is not returning RPC replies.

The approach I've taken is to disable RPC_TASK_NO_RETRANS_TIMEOUT
for a few particular operations to enable them to time out even
though the connection is still operational. It could be
appropriate to take this approach for any idempotent operation
that cannot be killed with a ^C.

Changes since RFC:
- Dropped changes to async lease renewal and DESTROY_SESSION|CLIENTID
- Cleaned up some tracepoint issues I found along the way

---

Chuck Lever (6):
      SUNRPC: Refactor rpc_ping()
      SUNRPC: Unset RPC_TASK_NO_RETRANS_TIMEOUT for NULL RPCs
      SUNRPC: Remove unneeded TRACE_DEFINE_ENUMs
      SUNRPC: Update trace flags
      SUNRPC: xprt_retransmit() displays the the NULL procedure incorrectly
      SUNRPC: Record timeout value in xprt_retransmit tracepoint


 include/trace/events/sunrpc.h | 51 ++++++++---------------------------
 net/sunrpc/clnt.c             | 33 ++++++++++++++++-------
 2 files changed, 35 insertions(+), 49 deletions(-)

--
Chuck Lever

[PATCH v2 1/6] SUNRPC: Refactor rpc_ping()

[Chuck Lever]

Make it use the rpc_null_call_helper() so that it can share the
new rpc_call_ops structure to be introduced in the next patch.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 net/sunrpc/clnt.c |   24 +++++++++++++-----------
 1 file changed, 13 insertions(+), 11 deletions(-)

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index 8b4de70e8ead..ca2000d8cf64 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -2694,17 +2694,6 @@ static const struct rpc_procinfo rpcproc_null = {
 	.p_decode = rpcproc_decode_null,
 };
 
-static int rpc_ping(struct rpc_clnt *clnt)
-{
-	struct rpc_message msg = {
-		.rpc_proc = &rpcproc_null,
-	};
-	int err;
-	err = rpc_call_sync(clnt, &msg, RPC_TASK_SOFT | RPC_TASK_SOFTCONN |
-			    RPC_TASK_NULLCREDS);
-	return err;
-}
-
 static
 struct rpc_task *rpc_call_null_helper(struct rpc_clnt *clnt,
 		struct rpc_xprt *xprt, struct rpc_cred *cred, int flags,
@@ -2733,6 +2722,19 @@ struct rpc_task *rpc_call_null(struct rpc_clnt *clnt, struct rpc_cred *cred, int
 }
 EXPORT_SYMBOL_GPL(rpc_call_null);
 
+static int rpc_ping(struct rpc_clnt *clnt)
+{
+	struct rpc_task	*task;
+	int status;
+
+	task = rpc_call_null_helper(clnt, NULL, NULL, 0, NULL, NULL);
+	if (IS_ERR(task))
+		return PTR_ERR(task);
+	status = task->tk_status;
+	rpc_put_task(task);
+	return status;
+}
+
 struct rpc_cb_add_xprt_calldata {
 	struct rpc_xprt_switch *xps;
 	struct rpc_xprt *xprt;

[PATCH v2 2/6] SUNRPC: Unset RPC_TASK_NO_RETRANS_TIMEOUT for NULL RPCs

[Chuck Lever]

In some rare failure modes, the server is actually reading the
transport, but then just dropping the requests on the floor.
TCP_USER_TIMEOUT cannot detect that case.

Prevent such a stuck server from pinning client resources
indefinitely by ensuring that certain idempotent requests
(such as NULL) can time out even if the connection is still
operational.

Otherwise rpc_bind_new_program(), gss_destroy_cred(), or
rpc_clnt_test_and_add_xprt() can wait forever.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 net/sunrpc/clnt.c |   15 ++++++++++++++-
 1 file changed, 14 insertions(+), 1 deletion(-)

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index ca2000d8cf64..d34737a8a68a 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -2694,6 +2694,18 @@ static const struct rpc_procinfo rpcproc_null = {
 	.p_decode = rpcproc_decode_null,
 };
 
+static void
+rpc_null_call_prepare(struct rpc_task *task, void *data)
+{
+	task->tk_flags &= ~RPC_TASK_NO_RETRANS_TIMEOUT;
+	rpc_call_start(task);
+}
+
+static const struct rpc_call_ops rpc_null_ops = {
+	.rpc_call_prepare = rpc_null_call_prepare,
+	.rpc_call_done = rpc_default_callback,
+};
+
 static
 struct rpc_task *rpc_call_null_helper(struct rpc_clnt *clnt,
 		struct rpc_xprt *xprt, struct rpc_cred *cred, int flags,
@@ -2707,7 +2719,7 @@ struct rpc_task *rpc_call_null_helper(struct rpc_clnt *clnt,
 		.rpc_xprt = xprt,
 		.rpc_message = &msg,
 		.rpc_op_cred = cred,
-		.callback_ops = (ops != NULL) ? ops : &rpc_default_ops,
+		.callback_ops = ops ?: &rpc_null_ops,
 		.callback_data = data,
 		.flags = flags | RPC_TASK_SOFT | RPC_TASK_SOFTCONN |
 			 RPC_TASK_NULLCREDS,
@@ -2758,6 +2770,7 @@ static void rpc_cb_add_xprt_release(void *calldata)
 }
 
 static const struct rpc_call_ops rpc_cb_add_xprt_call_ops = {
+	.rpc_call_prepare = rpc_null_call_prepare,
 	.rpc_call_done = rpc_cb_add_xprt_done,
 	.rpc_release = rpc_cb_add_xprt_release,
 };

[PATCH v2 3/6] SUNRPC: Remove unneeded TRACE_DEFINE_ENUMs

[Chuck Lever]

Clean up: TRACE_DEFINE_ENUM is needed only for enums, not for
C macros.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 include/trace/events/sunrpc.h |   34 ----------------------------------
 1 file changed, 34 deletions(-)

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 861f199896c6..ea6340129b1b 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -295,21 +295,6 @@ TRACE_EVENT(rpc_request,
 		)
 );
 
-TRACE_DEFINE_ENUM(RPC_TASK_ASYNC);
-TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER);
-TRACE_DEFINE_ENUM(RPC_TASK_NULLCREDS);
-TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN);
-TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS);
-TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC);
-TRACE_DEFINE_ENUM(RPC_TASK_NO_ROUND_ROBIN);
-TRACE_DEFINE_ENUM(RPC_TASK_SOFT);
-TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
-TRACE_DEFINE_ENUM(RPC_TASK_SENT);
-TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
-TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
-TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT);
-TRACE_DEFINE_ENUM(RPC_TASK_CRED_NOREF);
-
 #define rpc_show_task_flags(flags)					\
 	__print_flags(flags, "|",					\
 		{ RPC_TASK_ASYNC, "ASYNC" },				\
@@ -327,14 +312,6 @@ TRACE_DEFINE_ENUM(RPC_TASK_CRED_NOREF);
 		{ RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" },		\
 		{ RPC_TASK_CRED_NOREF, "CRED_NOREF" })
 
-TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
-TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
-TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
-TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
-TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
-TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
-TRACE_DEFINE_ENUM(RPC_TASK_SIGNALLED);
-
 #define rpc_show_runstate(flags)					\
 	__print_flags(flags, "|",					\
 		{ (1UL << RPC_TASK_RUNNING), "RUNNING" },		\
@@ -945,17 +922,6 @@ TRACE_EVENT(rpc_socket_nospace,
 	)
 );
 
-TRACE_DEFINE_ENUM(XPRT_LOCKED);
-TRACE_DEFINE_ENUM(XPRT_CONNECTED);
-TRACE_DEFINE_ENUM(XPRT_CONNECTING);
-TRACE_DEFINE_ENUM(XPRT_CLOSE_WAIT);
-TRACE_DEFINE_ENUM(XPRT_BOUND);
-TRACE_DEFINE_ENUM(XPRT_BINDING);
-TRACE_DEFINE_ENUM(XPRT_CLOSING);
-TRACE_DEFINE_ENUM(XPRT_CONGESTED);
-TRACE_DEFINE_ENUM(XPRT_CWND_WAIT);
-TRACE_DEFINE_ENUM(XPRT_WRITE_SPACE);
-
 #define rpc_show_xprt_state(x)						\
 	__print_flags(x, "|",						\
 		{ (1UL << XPRT_LOCKED),		"LOCKED"},		\

[PATCH v2 4/6] SUNRPC: Update trace flags

[Chuck Lever]

Recent patches added RPC_TASK_MOVEABLE, XPRT_OFFLINE, and
XPRT_REMOVE. Update the tracepoint display macros to display these
flags properly.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 include/trace/events/sunrpc.h |    3 +++
 1 file changed, 3 insertions(+)

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index ea6340129b1b..b13130903a50 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -299,6 +299,7 @@ TRACE_EVENT(rpc_request,
 	__print_flags(flags, "|",					\
 		{ RPC_TASK_ASYNC, "ASYNC" },				\
 		{ RPC_TASK_SWAPPER, "SWAPPER" },			\
+		{ RPC_TASK_MOVEABLE, "MOVEABLE" },			\
 		{ RPC_TASK_NULLCREDS, "NULLCREDS" },			\
 		{ RPC_CALL_MAJORSEEN, "MAJORSEEN" },			\
 		{ RPC_TASK_ROOTCREDS, "ROOTCREDS" },			\
@@ -931,6 +932,8 @@ TRACE_EVENT(rpc_socket_nospace,
 		{ (1UL << XPRT_BOUND),		"BOUND"},		\
 		{ (1UL << XPRT_BINDING),	"BINDING"},		\
 		{ (1UL << XPRT_CLOSING),	"CLOSING"},		\
+		{ (1UL << XPRT_OFFLINE),	"OFFLINE"},		\
+		{ (1UL << XPRT_REMOVE),		"REMOVE"},		\
 		{ (1UL << XPRT_CONGESTED),	"CONGESTED"},		\
 		{ (1UL << XPRT_CWND_WAIT),	"CWND_WAIT"},		\
 		{ (1UL << XPRT_WRITE_SPACE),	"WRITE_SPACE"})

[PATCH v2 5/6] SUNRPC: xprt_retransmit() displays the the NULL procedure incorrectly

[Chuck Lever]

Currently:

  xprt_retransmit:      task:11@1 xid=0x55a7ffac nfsv4 (null) ntrans=2

should be:

  xprt_retransmit:      task:11@1 xid=0x55a7ffac nfsv4 NULL ntrans=2

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 include/trace/events/sunrpc.h |   10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index b13130903a50..59ad1718496b 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -1063,8 +1063,7 @@ TRACE_EVENT(xprt_retransmit,
 		__field(int, version)
 		__string(progname,
 			 rqst->rq_task->tk_client->cl_program->name)
-		__string(procedure,
-			 rqst->rq_task->tk_msg.rpc_proc->p_name)
+		__string(procname, rpc_proc_name(rqst->rq_task))
 	),
 
 	TP_fast_assign(
@@ -1078,14 +1077,15 @@ TRACE_EVENT(xprt_retransmit,
 		__assign_str(progname,
 			     task->tk_client->cl_program->name);
 		__entry->version = task->tk_client->cl_vers;
-		__assign_str(procedure, task->tk_msg.rpc_proc->p_name);
+		__assign_str(procname, rpc_proc_name(task));
 	),
 
 	TP_printk(
 		"task:%u@%u xid=0x%08x %sv%d %s ntrans=%d",
 		__entry->task_id, __entry->client_id, __entry->xid,
-		__get_str(progname), __entry->version, __get_str(procedure),
-		__entry->ntrans)
+		__get_str(progname), __entry->version, __get_str(procname),
+		__entry->ntrans
+	)
 );
 
 TRACE_EVENT(xprt_ping,

[PATCH v2 6/6] SUNRPC: Record timeout value in xprt_retransmit tracepoint

[Chuck Lever]

The client can alter the timeout value after each retransmit. Record
the updated timeout value in the trace log.

Suggested-by: Dai Ngo <dai.ngo@oracle.com>
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 include/trace/events/sunrpc.h |    6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 59ad1718496b..18d552a17c19 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -1061,6 +1061,7 @@ TRACE_EVENT(xprt_retransmit,
 		__field(u32, xid)
 		__field(int, ntrans)
 		__field(int, version)
+		__field(unsigned long, timeout)
 		__string(progname,
 			 rqst->rq_task->tk_client->cl_program->name)
 		__string(procname, rpc_proc_name(rqst->rq_task))
@@ -1074,6 +1075,7 @@ TRACE_EVENT(xprt_retransmit,
 			task->tk_client->cl_clid : -1;
 		__entry->xid = be32_to_cpu(rqst->rq_xid);
 		__entry->ntrans = rqst->rq_ntrans;
+		__entry->timeout = task->tk_timeout;
 		__assign_str(progname,
 			     task->tk_client->cl_program->name);
 		__entry->version = task->tk_client->cl_vers;
@@ -1081,10 +1083,10 @@ TRACE_EVENT(xprt_retransmit,
 	),
 
 	TP_printk(
-		"task:%u@%u xid=0x%08x %sv%d %s ntrans=%d",
+		"task:%u@%u xid=0x%08x %sv%d %s ntrans=%d timeout=%lu",
 		__entry->task_id, __entry->client_id, __entry->xid,
 		__get_str(progname), __entry->version, __get_str(procname),
-		__entry->ntrans
+		__entry->ntrans, __entry->timeout
 	)
 );
 

Re: [PATCH v2 0/6] Ensure RPC_TASK_NORTO is disabled for select operations

[Anna Schumaker]

Hi Chuck,

On Mon, Jul 19, 2021 at 10:55 AM Chuck Lever <chuck.lever@oracle.com> wrote:
>
> This is a set of patches I've been toying with to get better
> responsiveness from a client when a transport remains connected but
> the server is not returning RPC replies.
>
> The approach I've taken is to disable RPC_TASK_NO_RETRANS_TIMEOUT
> for a few particular operations to enable them to time out even
> though the connection is still operational. It could be
> appropriate to take this approach for any idempotent operation
> that cannot be killed with a ^C.
>
> Changes since RFC:
> - Dropped changes to async lease renewal and DESTROY_SESSION|CLIENTID
> - Cleaned up some tracepoint issues I found along the way

Is this the latest version of these patches? If so I can include them
in my linux-next branch for 5.14.

Thanks,
Anna

>
> ---
>
> Chuck Lever (6):
>       SUNRPC: Refactor rpc_ping()
>       SUNRPC: Unset RPC_TASK_NO_RETRANS_TIMEOUT for NULL RPCs
>       SUNRPC: Remove unneeded TRACE_DEFINE_ENUMs
>       SUNRPC: Update trace flags
>       SUNRPC: xprt_retransmit() displays the the NULL procedure incorrectly
>       SUNRPC: Record timeout value in xprt_retransmit tracepoint
>
>
>  include/trace/events/sunrpc.h | 51 ++++++++---------------------------
>  net/sunrpc/clnt.c             | 33 ++++++++++++++++-------
>  2 files changed, 35 insertions(+), 49 deletions(-)
>
> --
> Chuck Lever
>

Re: [PATCH v2 0/6] Ensure RPC_TASK_NORTO is disabled for select operations

[Chuck Lever III]

> On Aug 9, 2021, at 4:37 PM, Anna Schumaker <anna.schumaker@netapp.com> wrote:
> 
> Hi Chuck,
> 
> On Mon, Jul 19, 2021 at 10:55 AM Chuck Lever <chuck.lever@oracle.com> wrote:
>> 
>> This is a set of patches I've been toying with to get better
>> responsiveness from a client when a transport remains connected but
>> the server is not returning RPC replies.
>> 
>> The approach I've taken is to disable RPC_TASK_NO_RETRANS_TIMEOUT
>> for a few particular operations to enable them to time out even
>> though the connection is still operational. It could be
>> appropriate to take this approach for any idempotent operation
>> that cannot be killed with a ^C.
>> 
>> Changes since RFC:
>> - Dropped changes to async lease renewal and DESTROY_SESSION|CLIENTID
>> - Cleaned up some tracepoint issues I found along the way
> 
> Is this the latest version of these patches? If so I can include them
> in my linux-next branch for 5.14.

AFAIR v2 is the latest, yes. Thanks!


> Thanks,
> Anna
> 
>> 
>> ---
>> 
>> Chuck Lever (6):
>>      SUNRPC: Refactor rpc_ping()
>>      SUNRPC: Unset RPC_TASK_NO_RETRANS_TIMEOUT for NULL RPCs
>>      SUNRPC: Remove unneeded TRACE_DEFINE_ENUMs
>>      SUNRPC: Update trace flags
>>      SUNRPC: xprt_retransmit() displays the the NULL procedure incorrectly
>>      SUNRPC: Record timeout value in xprt_retransmit tracepoint
>> 
>> 
>> include/trace/events/sunrpc.h | 51 ++++++++---------------------------
>> net/sunrpc/clnt.c             | 33 ++++++++++++++++-------
>> 2 files changed, 35 insertions(+), 49 deletions(-)
>> 
>> --
>> Chuck Lever

--
Chuck Lever

Re: [PATCH v2 0/6] Ensure RPC_TASK_NORTO is disabled for select operations

[Anna Schumaker]

On Mon, Aug 9, 2021 at 7:00 PM Chuck Lever III <chuck.lever@oracle.com> wrote:
>
>
>
> > On Aug 9, 2021, at 4:37 PM, Anna Schumaker <anna.schumaker@netapp.com> wrote:
> >
> > Hi Chuck,
> >
> > On Mon, Jul 19, 2021 at 10:55 AM Chuck Lever <chuck.lever@oracle.com> wrote:
> >>
> >> This is a set of patches I've been toying with to get better
> >> responsiveness from a client when a transport remains connected but
> >> the server is not returning RPC replies.
> >>
> >> The approach I've taken is to disable RPC_TASK_NO_RETRANS_TIMEOUT
> >> for a few particular operations to enable them to time out even
> >> though the connection is still operational. It could be
> >> appropriate to take this approach for any idempotent operation
> >> that cannot be killed with a ^C.
> >>
> >> Changes since RFC:
> >> - Dropped changes to async lease renewal and DESTROY_SESSION|CLIENTID
> >> - Cleaned up some tracepoint issues I found along the way
> >
> > Is this the latest version of these patches? If so I can include them
> > in my linux-next branch for 5.14.
>
> AFAIR v2 is the latest, yes. Thanks!

Great, I have them applied!

Anna
>
>
> > Thanks,
> > Anna
> >
> >>
> >> ---
> >>
> >> Chuck Lever (6):
> >>      SUNRPC: Refactor rpc_ping()
> >>      SUNRPC: Unset RPC_TASK_NO_RETRANS_TIMEOUT for NULL RPCs
> >>      SUNRPC: Remove unneeded TRACE_DEFINE_ENUMs
> >>      SUNRPC: Update trace flags
> >>      SUNRPC: xprt_retransmit() displays the the NULL procedure incorrectly
> >>      SUNRPC: Record timeout value in xprt_retransmit tracepoint
> >>
> >>
> >> include/trace/events/sunrpc.h | 51 ++++++++---------------------------
> >> net/sunrpc/clnt.c             | 33 ++++++++++++++++-------
> >> 2 files changed, 35 insertions(+), 49 deletions(-)
> >>
> >> --
> >> Chuck Lever
>
> --
> Chuck Lever
>
>
>