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

["Anna Schumaker" <anna@kernel.org>]

Hi Manjunath,

On Wed, Aug 19, 2026, at 1:30 PM, Manjunath Patil 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 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",

More observability around this makes sense. Any reason you're adding to the notice
here and not making it a new tracepoint for the extra information? I'm worried
people might have tooling around watching for unresponsive servers and this
might break whatever regexes they're using to look for this.

Anna

>  				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