[PATCH] SUNRPC: add transport details to timeout diagnostics

[PATCH] SUNRPC: add transport details to timeout diagnostics

[Manjunath Patil]

The existing RPC timeout messages identify only the RPC program and
server name. That makes it difficult to distinguish a server-side
response stall from a transport that is disconnected, reconnecting,
or using a different connection.

Include the RPC client id, transport id, current transport connection
cookie, and RPC task owner in the ratelimited timeout messages. These
fields provide a compact way to correlate a timeout message with
rpcctl and other transport state.

For example, an NFS timeout reports:

  nfs: server 192.168.50.1 clid=4 xprt=1 cc=1 owner=6245
  not responding, timed out

Assisted-by: Codex:gpt-5
Signed-off-by: Manjunath Patil <manjunath.b.patil@oracle.com>
---
 net/sunrpc/clnt.c | 20 +++++++++++++-------
 1 file changed, 13 insertions(+), 7 deletions(-)

diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index efa26899bc7d..6b5e2787dc81 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -2534,17 +2534,21 @@ static void
 rpc_check_timeout(struct rpc_task *task)
 {
 	struct rpc_clnt	*clnt = task->tk_client;
+	struct rpc_rqst	*req;
+	struct rpc_xprt	*xprt;
 
 	if (RPC_SIGNALLED(task))
 		return;
 
-	if (xprt_adjust_timeout(task->tk_rqstp) == 0)
+	req = task->tk_rqstp;
+	if (xprt_adjust_timeout(req) == 0)
 		return;
+	xprt = req->rq_xprt;
 
 	trace_rpc_timeout_status(task);
 	task->tk_timeouts++;
 
-	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(task->tk_rqstp)) {
+	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(req)) {
 		rpc_call_rpcerror(task, -ETIMEDOUT);
 		return;
 	}
@@ -2556,14 +2560,15 @@ rpc_check_timeout(struct rpc_task *task)
 		 * connection gets terminally broken.
 		 */
 		if ((task->tk_flags & RPC_TASK_NO_RETRANS_TIMEOUT) &&
-		    rpc_check_connected(task->tk_rqstp))
+		    rpc_check_connected(req))
 			return;
 
 		if (clnt->cl_chatty) {
 			pr_notice_ratelimited(
-				"%s: server %s not responding, timed out\n",
+				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, timed out\n",
 				clnt->cl_program->name,
-				task->tk_xprt->servername);
+				xprt->servername, clnt->cl_clid, xprt->id,
+				READ_ONCE(xprt->connect_cookie), task->tk_owner);
 		}
 		if (task->tk_flags & RPC_TASK_TIMEOUT)
 			rpc_call_rpcerror(task, -ETIMEDOUT);
@@ -2576,9 +2581,10 @@ rpc_check_timeout(struct rpc_task *task)
 		task->tk_flags |= RPC_CALL_MAJORSEEN;
 		if (clnt->cl_chatty) {
 			pr_notice_ratelimited(
-				"%s: server %s not responding, still trying\n",
+				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, still trying\n",
 				clnt->cl_program->name,
-				task->tk_xprt->servername);
+				xprt->servername, clnt->cl_clid, xprt->id,
+				READ_ONCE(xprt->connect_cookie), task->tk_owner);
 		}
 	}
 	rpc_force_rebind(clnt);
-- 
2.47.3

[PATCH] SUNRPC: add transport details to timeout diagnostics

[Petr Vorel]

> The existing RPC timeout messages identify only the RPC program and
> server name. That makes it difficult to distinguish a server-side
> response stall from a transport that is disconnected, reconnecting,
> or using a different connection.
> 
> Include the RPC client id, transport id, current transport connection
> cookie, and RPC task owner in the ratelimited timeout messages. These
> fields provide a compact way to correlate a timeout message with
> rpcctl and other transport state.
> 
> For example, an NFS timeout reports:
> 
>   nfs: server 192.168.50.1 clid=4 xprt=1 cc=1 owner=6245
>   not responding, timed out

Nice improvement, thanks!

> 
> Assisted-by: Codex:gpt-5
> Signed-off-by: Manjunath Patil <manjunath.b.patil@oracle.com>
> ---
>  net/sunrpc/clnt.c | 20 +++++++++++++-------
>  1 file changed, 13 insertions(+), 7 deletions(-)
> 
> diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
> index efa26899bc7d..6b5e2787dc81 100644
> --- a/net/sunrpc/clnt.c
> +++ b/net/sunrpc/clnt.c
> @@ -2534,17 +2534,21 @@ static void
>  rpc_check_timeout(struct rpc_task *task)
>  {
>  	struct rpc_clnt	*clnt = task->tk_client;
> +	struct rpc_rqst	*req;
> +	struct rpc_xprt	*xprt;

nit: Would it work to assign req and task earlier (just readability?)
Or is it not safe before checking RPC_SIGNALLED(task)?

	struct rpc_clnt	*clnt = task->tk_client;
	struct rpc_rqst	*req = task->tk_rqstp;
	struct rpc_xprt	*xprt = req->rq_xprt;

The rest LGTM.
Reviewed-by: Petr Vorel <pvorel@suse.cz>

Kind regards,
Petr


>  
>  	if (RPC_SIGNALLED(task))
>  		return;
>  
> -	if (xprt_adjust_timeout(task->tk_rqstp) == 0)
> +	req = task->tk_rqstp;
> +	if (xprt_adjust_timeout(req) == 0)
>  		return;
> +	xprt = req->rq_xprt;
>  
>  	trace_rpc_timeout_status(task);
>  	task->tk_timeouts++;
>  
> -	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(task->tk_rqstp)) {
> +	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(req)) {
>  		rpc_call_rpcerror(task, -ETIMEDOUT);
>  		return;
>  	}
> @@ -2556,14 +2560,15 @@ rpc_check_timeout(struct rpc_task *task)
>  		 * connection gets terminally broken.
>  		 */
>  		if ((task->tk_flags & RPC_TASK_NO_RETRANS_TIMEOUT) &&
> -		    rpc_check_connected(task->tk_rqstp))
> +		    rpc_check_connected(req))
>  			return;
>  
>  		if (clnt->cl_chatty) {
>  			pr_notice_ratelimited(
> -				"%s: server %s not responding, timed out\n",
> +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, timed out\n",
>  				clnt->cl_program->name,
> -				task->tk_xprt->servername);
> +				xprt->servername, clnt->cl_clid, xprt->id,
> +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
>  		}
>  		if (task->tk_flags & RPC_TASK_TIMEOUT)
>  			rpc_call_rpcerror(task, -ETIMEDOUT);
> @@ -2576,9 +2581,10 @@ rpc_check_timeout(struct rpc_task *task)
>  		task->tk_flags |= RPC_CALL_MAJORSEEN;
>  		if (clnt->cl_chatty) {
>  			pr_notice_ratelimited(
> -				"%s: server %s not responding, still trying\n",
> +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, still trying\n",
>  				clnt->cl_program->name,
> -				task->tk_xprt->servername);
> +				xprt->servername, clnt->cl_clid, xprt->id,
> +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
>  		}
>  	}
>  	rpc_force_rebind(clnt);

Re: [PATCH] SUNRPC: add transport details to timeout diagnostics

[manjunath.b.patil]

On 8/20/26 4:13 AM, Petr Vorel wrote:
>  > The existing RPC timeout messages identify only the RPC program and > 
> server name. That makes it difficult to distinguish a server-side > 
> response stall from a transport that is disconnected, reconnecting, > or 
> using a different
> 
> 
>> The existing RPC timeout messages identify only the RPC program and
>> server name. That makes it difficult to distinguish a server-side
>> response stall from a transport that is disconnected, reconnecting,
>> or using a different connection.
>> 
>> Include the RPC client id, transport id, current transport connection
>> cookie, and RPC task owner in the ratelimited timeout messages. These
>> fields provide a compact way to correlate a timeout message with
>> rpcctl and other transport state.
>> 
>> For example, an NFS timeout reports:
>> 
>>   nfs: server 192.168.50.1 clid=4 xprt=1 cc=1 owner=6245
>>   not responding, timed out
> 
> Nice improvement, thanks!
> 
>> 
>> Assisted-by: Codex:gpt-5
>> Signed-off-by: Manjunath Patil <manjunath.b.patil@oracle.com>
>> ---
>>  net/sunrpc/clnt.c | 20 +++++++++++++-------
>>  1 file changed, 13 insertions(+), 7 deletions(-)
>> 
>> diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
>> index efa26899bc7d..6b5e2787dc81 100644
>> --- a/net/sunrpc/clnt.c
>> +++ b/net/sunrpc/clnt.c
>> @@ -2534,17 +2534,21 @@ static void
>>  rpc_check_timeout(struct rpc_task *task)
>>  {
>>  	struct rpc_clnt	*clnt = task->tk_client;
>> +	struct rpc_rqst	*req;
>> +	struct rpc_xprt	*xprt;
> 
> nit: Would it work to assign req and task earlier (just readability?)
> Or is it not safe before checking RPC_SIGNALLED(task)?
> 
> 	struct rpc_clnt	*clnt = task->tk_client;
> 	struct rpc_rqst	*req = task->tk_rqstp;
> 	struct rpc_xprt	*xprt = req->rq_xprt;
> 
> The rest LGTM.
> Reviewed-by: Petr Vorel <pvorel@suse.cz>
> 
> Kind regards,
> Petr

Hi Petr,

Thanks for the review and the Reviewed-by tag.

I kept the assignments after RPC_SIGNALLED(task) intentionally, 
preserving the existing behavior where a signalled task returns before 
we dereference task->tk_rqstp. xprt is also needed only after 
xprt_adjust_timeout(req) reports an expired timeout.

I would prefer to retain the current ordering for those reasons. Also I 
am open if maintainers chose to alter it.

Thanks, 
  
                 Manjunath
> 
> 
>>  
>>  	if (RPC_SIGNALLED(task))
>>  		return;
>>  
>> -	if (xprt_adjust_timeout(task->tk_rqstp) == 0)
>> +	req = task->tk_rqstp;
>> +	if (xprt_adjust_timeout(req) == 0)
>>  		return;
>> +	xprt = req->rq_xprt;
>>  
>>  	trace_rpc_timeout_status(task);
>>  	task->tk_timeouts++;
>>  
>> -	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(task->tk_rqstp)) {
>> +	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(req)) {
>>  		rpc_call_rpcerror(task, -ETIMEDOUT);
>>  		return;
>>  	}
>> @@ -2556,14 +2560,15 @@ rpc_check_timeout(struct rpc_task *task)
>>  		 * connection gets terminally broken.
>>  		 */
>>  		if ((task->tk_flags & RPC_TASK_NO_RETRANS_TIMEOUT) &&
>> -		    rpc_check_connected(task->tk_rqstp))
>> +		    rpc_check_connected(req))
>>  			return;
>>  
>>  		if (clnt->cl_chatty) {
>>  			pr_notice_ratelimited(
>> -				"%s: server %s not responding, timed out\n",
>> +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, timed out\n",
>>  				clnt->cl_program->name,
>> -				task->tk_xprt->servername);
>> +				xprt->servername, clnt->cl_clid, xprt->id,
>> +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
>>  		}
>>  		if (task->tk_flags & RPC_TASK_TIMEOUT)
>>  			rpc_call_rpcerror(task, -ETIMEDOUT);
>> @@ -2576,9 +2581,10 @@ rpc_check_timeout(struct rpc_task *task)
>>  		task->tk_flags |= RPC_CALL_MAJORSEEN;
>>  		if (clnt->cl_chatty) {
>>  			pr_notice_ratelimited(
>> -				"%s: server %s not responding, still trying\n",
>> +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, still trying\n",
>>  				clnt->cl_program->name,
>> -				task->tk_xprt->servername);
>> +				xprt->servername, clnt->cl_clid, xprt->id,
>> +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
>>  		}
>>  	}
>>  	rpc_force_rebind(clnt);
> 

Re: [PATCH] SUNRPC: add transport details to timeout diagnostics

[Petr Vorel]

> On 8/20/26 4:13 AM, Petr Vorel wrote:
> >  > The existing RPC timeout messages identify only the RPC program and >
> > server name. That makes it difficult to distinguish a server-side >
> > response stall from a transport that is disconnected, reconnecting, > or
> > using a different


> > > The existing RPC timeout messages identify only the RPC program and
> > > server name. That makes it difficult to distinguish a server-side
> > > response stall from a transport that is disconnected, reconnecting,
> > > or using a different connection.

> > > Include the RPC client id, transport id, current transport connection
> > > cookie, and RPC task owner in the ratelimited timeout messages. These
> > > fields provide a compact way to correlate a timeout message with
> > > rpcctl and other transport state.

> > > For example, an NFS timeout reports:

> > >   nfs: server 192.168.50.1 clid=4 xprt=1 cc=1 owner=6245
> > >   not responding, timed out

> > Nice improvement, thanks!


> > > Assisted-by: Codex:gpt-5
> > > Signed-off-by: Manjunath Patil <manjunath.b.patil@oracle.com>
> > > ---
> > >  net/sunrpc/clnt.c | 20 +++++++++++++-------
> > >  1 file changed, 13 insertions(+), 7 deletions(-)

> > > diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
> > > index efa26899bc7d..6b5e2787dc81 100644
> > > --- a/net/sunrpc/clnt.c
> > > +++ b/net/sunrpc/clnt.c
> > > @@ -2534,17 +2534,21 @@ static void
> > >  rpc_check_timeout(struct rpc_task *task)
> > >  {
> > >  	struct rpc_clnt	*clnt = task->tk_client;
> > > +	struct rpc_rqst	*req;
> > > +	struct rpc_xprt	*xprt;

> > nit: Would it work to assign req and task earlier (just readability?)
> > Or is it not safe before checking RPC_SIGNALLED(task)?

> > 	struct rpc_clnt	*clnt = task->tk_client;
> > 	struct rpc_rqst	*req = task->tk_rqstp;
> > 	struct rpc_xprt	*xprt = req->rq_xprt;

> > The rest LGTM.
> > Reviewed-by: Petr Vorel <pvorel@suse.cz>

> > Kind regards,
> > Petr

> Hi Petr,

Hi Manjunath,

> Thanks for the review and the Reviewed-by tag.

yw.

> I kept the assignments after RPC_SIGNALLED(task) intentionally, preserving
> the existing behavior where a signalled task returns before we dereference
> task->tk_rqstp. xprt is also needed only after xprt_adjust_timeout(req)
> reports an expired timeout.

Understand, fair enough.

> I would prefer to retain the current ordering for those reasons. Also I am
> open if maintainers chose to alter it.

+1

Kind regards,
Petr

> Thanks,                   Manjunath


> > >  	if (RPC_SIGNALLED(task))
> > >  		return;
> > > -	if (xprt_adjust_timeout(task->tk_rqstp) == 0)
> > > +	req = task->tk_rqstp;
> > > +	if (xprt_adjust_timeout(req) == 0)
> > >  		return;
> > > +	xprt = req->rq_xprt;
> > >  	trace_rpc_timeout_status(task);
> > >  	task->tk_timeouts++;
> > > -	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(task->tk_rqstp)) {
> > > +	if (RPC_IS_SOFTCONN(task) && !rpc_check_connected(req)) {
> > >  		rpc_call_rpcerror(task, -ETIMEDOUT);
> > >  		return;
> > >  	}
> > > @@ -2556,14 +2560,15 @@ rpc_check_timeout(struct rpc_task *task)
> > >  		 * connection gets terminally broken.
> > >  		 */
> > >  		if ((task->tk_flags & RPC_TASK_NO_RETRANS_TIMEOUT) &&
> > > -		    rpc_check_connected(task->tk_rqstp))
> > > +		    rpc_check_connected(req))
> > >  			return;
> > >  		if (clnt->cl_chatty) {
> > >  			pr_notice_ratelimited(
> > > -				"%s: server %s not responding, timed out\n",
> > > +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, timed out\n",
> > >  				clnt->cl_program->name,
> > > -				task->tk_xprt->servername);
> > > +				xprt->servername, clnt->cl_clid, xprt->id,
> > > +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
> > >  		}
> > >  		if (task->tk_flags & RPC_TASK_TIMEOUT)
> > >  			rpc_call_rpcerror(task, -ETIMEDOUT);
> > > @@ -2576,9 +2581,10 @@ rpc_check_timeout(struct rpc_task *task)
> > >  		task->tk_flags |= RPC_CALL_MAJORSEEN;
> > >  		if (clnt->cl_chatty) {
> > >  			pr_notice_ratelimited(
> > > -				"%s: server %s not responding, still trying\n",
> > > +				"%s: server %s clid=%u xprt=%u cc=%u owner=%d not responding, still trying\n",
> > >  				clnt->cl_program->name,
> > > -				task->tk_xprt->servername);
> > > +				xprt->servername, clnt->cl_clid, xprt->id,
> > > +				READ_ONCE(xprt->connect_cookie), task->tk_owner);
> > >  		}
> > >  	}
> > >  	rpc_force_rebind(clnt);