NFS problem in 5.16 merge content

NFS problem in 5.16 merge content

[Dennis Dalessandro]

Seeing NFS RDMA failures after pulling 5.16 content. Does this thing any bells?

[30847.409411] INFO: task kworker/u129:4:797744 blocked for more than 122 seconds.
[30847.417999]       Tainted: G S                5.16.0-rc1+ #1
[30847.424735] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[30847.433914] task:kworker/u129:4  state:D stack:    0 pid:797744 ppid:     2
flags:0x00004000
[30847.443870] Workqueue: rpciod rpc_async_schedule [sunrpc]
[30847.450418] Call Trace:
[30847.453625]  <TASK>
[30847.456388]  __schedule+0x3e3/0x9a0
[30847.460769]  ? _raw_spin_lock_irqsave+0x17/0x40
[30847.466219]  schedule+0x44/0xc0
[30847.470093]  xprt_request_dequeue_xprt+0xd1/0x140 [sunrpc]
[30847.476719]  ? init_wait_var_entry+0x50/0x50
[30847.481904]  ? rpc_destroy_wait_queue+0x10/0x10 [sunrpc]
[30847.488238]  xprt_release+0x26/0x140 [sunrpc]
[30847.493575]  ? rpc_destroy_wait_queue+0x10/0x10 [sunrpc]
[30847.499920]  rpc_release_resources_task+0xe/0x50 [sunrpc]
[30847.506352]  __rpc_execute+0x25d/0x460 [sunrpc]
[30847.511825]  rpc_async_schedule+0x29/0x40 [sunrpc]
[30847.517627]  process_one_work+0x1cb/0x3a0
[30847.522472]  worker_thread+0x30/0x380
[30847.526895]  ? process_one_work+0x3a0/0x3a0
[30847.531896]  kthread+0x167/0x190
[30847.535845]  ? set_kthread_struct+0x40/0x40
[30847.540850]  ret_from_fork+0x22/0x30
[30847.545164]  </TASK>

-Denny

Re: NFS problem in 5.16 merge content

[Chuck Lever III]

Hi Dennis-

> On Nov 23, 2021, at 5:19 PM, Dennis Dalessandro <dennis.dalessandro@cornelisnetworks.com> wrote:
> 
> Seeing NFS RDMA failures after pulling 5.16 content. Does this thing any bells?

No bells here.... but I don't see anything RDMA-related below.

If you can reproduce the issue:

1. # trace-cmd record -e sunrpc -e rpcrdma -e rdma_core -e rdma_cma

2.  ... reproduce ...

3.  ^C trace-cmd

4. Compress and e-mail the trace.dat file to me.


> [30847.409411] INFO: task kworker/u129:4:797744 blocked for more than 122 seconds.
> [30847.417999]       Tainted: G S                5.16.0-rc1+ #1
> [30847.424735] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
> message.
> [30847.433914] task:kworker/u129:4  state:D stack:    0 pid:797744 ppid:     2
> flags:0x00004000
> [30847.443870] Workqueue: rpciod rpc_async_schedule [sunrpc]
> [30847.450418] Call Trace:
> [30847.453625]  <TASK>
> [30847.456388]  __schedule+0x3e3/0x9a0
> [30847.460769]  ? _raw_spin_lock_irqsave+0x17/0x40
> [30847.466219]  schedule+0x44/0xc0
> [30847.470093]  xprt_request_dequeue_xprt+0xd1/0x140 [sunrpc]
> [30847.476719]  ? init_wait_var_entry+0x50/0x50
> [30847.481904]  ? rpc_destroy_wait_queue+0x10/0x10 [sunrpc]
> [30847.488238]  xprt_release+0x26/0x140 [sunrpc]
> [30847.493575]  ? rpc_destroy_wait_queue+0x10/0x10 [sunrpc]
> [30847.499920]  rpc_release_resources_task+0xe/0x50 [sunrpc]
> [30847.506352]  __rpc_execute+0x25d/0x460 [sunrpc]
> [30847.511825]  rpc_async_schedule+0x29/0x40 [sunrpc]
> [30847.517627]  process_one_work+0x1cb/0x3a0
> [30847.522472]  worker_thread+0x30/0x380
> [30847.526895]  ? process_one_work+0x3a0/0x3a0
> [30847.531896]  kthread+0x167/0x190
> [30847.535845]  ? set_kthread_struct+0x40/0x40
> [30847.540850]  ret_from_fork+0x22/0x30
> [30847.545164]  </TASK>
> 
> -Denny

--
Chuck Lever