There is a problem with nfs hang on my machine, Steps to reproduce:
1.
echo "options sunrpc tcp_slot_table_entries=2" >> /etc/modprobe.d/sunrpc.conf
echo "options sunrpc tcp_max_slot_table_entries=2" >> /etc/modprobe.d/sunrpc.conf
and remount nfsv3: sudo mount -t nfs -o vers=3,nolock,proto=tcp 127.0.0.1:/root/nfs_server/ /root/nfs_client/
2.Run case
# cat case.sh
while true
do
ls &
done &
while true
do
killall ls
done &
[root@cuibixuan nfs_client]# cd /root/nfs_client/; sh case.sh
3. Run 'killall sh' to kill case after waiting 10 seconds
4. The nfs hang and xprt->state is 0x212(XPRT_CONGESTED):
[root@cuibixuan sunrpc]# cat /sys/kernel/debug/sunrpc/rpc_xprt/4/info
netid: tcp
addr: 127.0.0.1
port: 2049
state: 0x212
[root@cuibixuan sunrpc]# cat /sys/kernel/debug/sunrpc/rpc_clnt/4/tasks
155 0080 -11 0x4 0x0 0 rpc_default_ops [sunrpc] nfsv3 GETATTR a:call_reserveresult [sunrpc] q:xprt_backlog
15418 0080 -11 0x4 0x0 0 rpc_default_ops [sunrpc] nfsv3 GETATTR a:call_reserveresult [sunrpc] q:xprt_backlog
5. Enable ftrace
# echo 1 > /sys/kernel/debug/tracing/events/sunrpc/enable
# cat /sys/kernel/debug/tracing/trace
...
ls-18792 [001] .... 668.541062: rpc_task_run_action: task:28885@4 flags=0080 state=0005 status=0 action=call_start [sunrpc]
ls-18792 [001] .... 668.541063: rpc_request: task:28885@4 nfsv3 GETATTR (sync)
ls-18792 [001] .... 668.541063: rpc_task_run_action: task:28885@4 flags=0080 state=0005 status=0 action=call_reserve [sunrpc]
ls-18792 [001] .... 668.541065: rpc_task_sleep: task:28885@4 flags=0080 state=0005 status=-11 timeout=0 queue=xprt_backlog
ls-18792 [000] .... 670.815066: rpc_task_wakeup: task:28885@4 flags=0180 state=0006 status=-512 timeout=0 queue=xprt_backlog
ls-18792 [000] .... 670.815069: rpc_task_run_action: task:28885@4 flags=0180 state=0005 status=-512 action=rpc_exit_task [sunrpc]
ls-18846 [001] .... 682.302970: rpc_task_begin: task:28886@4 flags=0080 state=0004 status=0 action= (null)
ls-18846 [001] .... 682.302972: rpc_task_run_action: task:28886@4 flags=0080 state=0005 status=0 action=call_start [sunrpc]
ls-18846 [001] .... 682.302973: rpc_request: task:28886@4 nfsv3 GETATTR (sync)
ls-18846 [001] .... 682.302973: rpc_task_run_action: task:28886@4 flags=0080 state=0005 status=0 action=call_reserve [sunrpc]
ls-18846 [001] .... 682.302974: rpc_task_sleep: task:28886@4 flags=0080 state=0005 status=-11 timeout=0 queue=xprt_backlog
ls-18846 [000] .... 684.690924: rpc_task_wakeup: task:28886@4 flags=0180 state=0006 status=-512 timeout=0 queue=xprt_backlog
ls-18846 [000] .... 684.690928: rpc_task_run_action: task:28886@4 flags=0180 state=0005 status=-512 action=rpc_exit_task [sunrpc]
The kernel version of my machine is 4.19.91, and it can be fixed with
the following patch (in v4.19):
diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index 793f595..2656048 100644
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -1358,6 +1358,7 @@ void xprt_release(struct rpc_task *task)
if (req == NULL) {
if (task->tk_client) {
xprt = task->tk_xprt;
+ xprt_wake_up_backlog(xprt);
if (xprt->snd_task == task)
xprt_release_write(xprt, task);
}
I checked the -next code, there should be the same problem.
Bixuan Cui (1):
SUNRPC: Clean XPRT_CONGESTED of xprt->state when rpc task is killed
net/sunrpc/xprt.c | 1 +
1 file changed, 1 insertion(+)
--
1.8.3.1
When the values of tcp_max_slot_table_entries and
sunrpc.tcp_slot_table_entries are lower than the number of rpc tasks,
xprt_dynamic_alloc_slot() in xprt_alloc_slot() will return -EAGAIN, and
then set xprt->state to XPRT_CONGESTED:
xprt_retry_reserve
->xprt_do_reserve
->xprt_alloc_slot
->xprt_dynamic_alloc_slot // return -EAGAIN and task->tk_rqstp is NULL
->xprt_add_backlog // set_bit(XPRT_CONGESTED, &xprt->state);
When rpc task is killed, XPRT_CONGESTED bit of xprt->state will not be
cleaned up and nfs hangs:
rpc_exit_task
->xprt_release // if (req == NULL) is true, then XPRT_CONGESTED
// bit not clean
Add xprt_wake_up_backlog(xprt) to clean XPRT_CONGESTED bit in
xprt_release().
Signed-off-by: Bixuan Cui <[email protected]>
Signed-off-by: Xiaohui Pei <[email protected]>
---
net/sunrpc/xprt.c | 1 +
1 file changed, 1 insertion(+)
diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index a02de2b..70d11ae 100644
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -1952,6 +1952,7 @@ void xprt_release(struct rpc_task *task)
if (req == NULL) {
if (task->tk_client) {
xprt = task->tk_xprt;
+ xprt_wake_up_backlog(xprt);
xprt_release_write(xprt, task);
}
return;
--
1.8.3.1
ping~
在 2021/12/14 下午9:53, Bixuan Cui 写道:
> When the values of tcp_max_slot_table_entries and
> sunrpc.tcp_slot_table_entries are lower than the number of rpc tasks,
> xprt_dynamic_alloc_slot() in xprt_alloc_slot() will return -EAGAIN, and
> then set xprt->state to XPRT_CONGESTED:
> xprt_retry_reserve
> ->xprt_do_reserve
> ->xprt_alloc_slot
> ->xprt_dynamic_alloc_slot // return -EAGAIN and task->tk_rqstp is NULL
> ->xprt_add_backlog // set_bit(XPRT_CONGESTED, &xprt->state);
>
> When rpc task is killed, XPRT_CONGESTED bit of xprt->state will not be
> cleaned up and nfs hangs:
> rpc_exit_task
> ->xprt_release // if (req == NULL) is true, then XPRT_CONGESTED
> // bit not clean
>
> Add xprt_wake_up_backlog(xprt) to clean XPRT_CONGESTED bit in
> xprt_release().
>
> Signed-off-by: Bixuan Cui <[email protected]>
> Signed-off-by: Xiaohui Pei <[email protected]>
> ---
> net/sunrpc/xprt.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
> index a02de2b..70d11ae 100644
> --- a/net/sunrpc/xprt.c
> +++ b/net/sunrpc/xprt.c
> @@ -1952,6 +1952,7 @@ void xprt_release(struct rpc_task *task)
> if (req == NULL) {
> if (task->tk_client) {
> xprt = task->tk_xprt;
> + xprt_wake_up_backlog(xprt);
> xprt_release_write(xprt, task);
> }
> return;
On Mon, 2021-12-20 at 11:39 +0800, Bixuan Cui wrote:
> ping~
>
> 在 2021/12/14 下午9:53, Bixuan Cui 写道:
> > When the values of tcp_max_slot_table_entries and
> > sunrpc.tcp_slot_table_entries are lower than the number of rpc
> > tasks,
> > xprt_dynamic_alloc_slot() in xprt_alloc_slot() will return -EAGAIN,
> > and
> > then set xprt->state to XPRT_CONGESTED:
> > xprt_retry_reserve
> > ->xprt_do_reserve
> > ->xprt_alloc_slot
> > ->xprt_dynamic_alloc_slot // return -EAGAIN and task-
> > >tk_rqstp is NULL
> > ->xprt_add_backlog // set_bit(XPRT_CONGESTED, &xprt-
> > >state);
> >
> > When rpc task is killed, XPRT_CONGESTED bit of xprt->state will not
> > be
> > cleaned up and nfs hangs:
> > rpc_exit_task
> > ->xprt_release // if (req == NULL) is true, then
> > XPRT_CONGESTED
> > // bit not clean
> >
> > Add xprt_wake_up_backlog(xprt) to clean XPRT_CONGESTED bit in
> > xprt_release().
I'm not seeing how this explanation makes sense. If the task doesn't
hold a slot, then freeing that task isn't going to clear the congestion
caused by all the slots being in use.
--
Trond Myklebust
Linux NFS client maintainer, Hammerspace
[email protected]
On Wed, 2021-12-22 at 10:55 +0800, Bixuan Cui wrote:
>
> 在 2021/12/21 上午2:22, Trond Myklebust 写道:
>
> > On Mon, 2021-12-20 at 11:39 +0800, Bixuan Cui wrote:
> >
> > > ping~
> > >
> > > 在 2021/12/14 下午9:53, Bixuan Cui 写道:
> > >
> > > > When the values of tcp_max_slot_table_entries and
> > > > sunrpc.tcp_slot_table_entries are lower than the number of rpc
> > > > tasks,
> > > > xprt_dynamic_alloc_slot() in xprt_alloc_slot() will return -
> > > > EAGAIN,
> > > > and
> > > > then set xprt->state to XPRT_CONGESTED:
> > > > xprt_retry_reserve
> > > > ->xprt_do_reserve
> > > > ->xprt_alloc_slot
> > > > ->xprt_dynamic_alloc_slot // return -EAGAIN and task-
> > > >
> > > > > tk_rqstp is NULL
> > > > ->xprt_add_backlog // set_bit(XPRT_CONGESTED, &xprt-
> > > >
> > > > > state);
> > > > When rpc task is killed, XPRT_CONGESTED bit of xprt->state will
> > > > not
> > > > be
> > > > cleaned up and nfs hangs:
> > > > rpc_exit_task
> > > > ->xprt_release // if (req == NULL) is true, then
> > > > XPRT_CONGESTED
> > > > // bit not clean
> > > >
> > > > Add xprt_wake_up_backlog(xprt) to clean XPRT_CONGESTED bit in
> > > > xprt_release().
> > I'm not seeing how this explanation makes sense. If the task
> > doesn't
> > hold a slot, then freeing that task isn't going to clear the
> > congestion
> > caused by all the slots being in use.
> Hi，
> If the rpc task is free, call xprt_release() :
> void xprt_release(struct rpc_task *task)
> {
> if (req == NULL) {
> if (task->tk_client) {
> xprt = task->tk_xprt;
> xprt_release_write(xprt, task); // 1.
> release xprt
> }
> return;
> }
> ....
> if (likely(!bc_prealloc(req)))
> xprt->ops->free_slot(xprt, req); // 2. release slot
> and call xprt_wake_up_backlog(xprt, req) to wakeup next task(clear
> XPRT_CONGESTED bit if next is NULL) in xprt_free_slot()
> else
> xprt_free_bc_request(req);
> }
> I mean that in step 1, xprt was only released, but
> xprt_wake_up_backlog was not called (I don’t know if it is necessary,
> but xprt->state may still be XPRT_CONGESTED), which causes xprt to
> hold up. I think it happens when the task that does not hold a slot
> is the last released task，xprt_wake_up_backlog(clear XPRT_CONGESTED)
> will not be executed. :-)
> Thanks，
> Bixuan Cui
>
>
My point is that in that case 1, there is no slot to free, so there is
no change to the congestion state.
IOW: your patch is incorrect because it is trying to assign a slot in a
case where there is no slot to assign.
--
Trond Myklebust
Linux NFS client maintainer, Hammerspace
[email protected]
在 2021/12/22 下午11:02, Trond Myklebust 写道:
> On Wed, 2021-12-22 at 10:55 +0800, Bixuan Cui wrote:
>> 在 2021/12/21 上午2:22, Trond Myklebust 写道:
>>
>>> On Mon, 2021-12-20 at 11:39 +0800, Bixuan Cui wrote:
>>>
>>>> ping~
>>>>
>>>> 在 2021/12/14 下午9:53, Bixuan Cui 写道:
>>>>
>>>>> When the values of tcp_max_slot_table_entries and
>>>>> sunrpc.tcp_slot_table_entries are lower than the number of rpc
>>>>> tasks,
>>>>> xprt_dynamic_alloc_slot() in xprt_alloc_slot() will return -
>>>>> EAGAIN,
>>>>> and
>>>>> then set xprt->state to XPRT_CONGESTED:
>>>>> xprt_retry_reserve
>>>>> ->xprt_do_reserve
>>>>> ->xprt_alloc_slot
>>>>> ->xprt_dynamic_alloc_slot // return -EAGAIN and task-
>>>>>
>>>>>> tk_rqstp is NULL
>>>>> ->xprt_add_backlog // set_bit(XPRT_CONGESTED, &xprt-
>>>>>
>>>>>> state);
>>>>> When rpc task is killed, XPRT_CONGESTED bit of xprt->state will
>>>>> not
>>>>> be
>>>>> cleaned up and nfs hangs:
>>>>> rpc_exit_task
>>>>> ->xprt_release // if (req == NULL) is true, then
>>>>> XPRT_CONGESTED
>>>>> // bit not clean
>>>>>
>>>>> Add xprt_wake_up_backlog(xprt) to clean XPRT_CONGESTED bit in
>>>>> xprt_release().
>>> I'm not seeing how this explanation makes sense. If the task
>>> doesn't
>>> hold a slot, then freeing that task isn't going to clear the
>>> congestion
>>> caused by all the slots being in use.
>> Hi，
>> If the rpc task is free, call xprt_release() :
>> void xprt_release(struct rpc_task *task)
>> {
>> if (req == NULL) {
>> if (task->tk_client) {
>> xprt = task->tk_xprt;
>> xprt_release_write(xprt, task); // 1.
>> release xprt
>> }
>> return;
>> }
>> ....
>> if (likely(!bc_prealloc(req)))
>> xprt->ops->free_slot(xprt, req); // 2. release slot
>> and call xprt_wake_up_backlog(xprt, req) to wakeup next task(clear
>> XPRT_CONGESTED bit if next is NULL) in xprt_free_slot()
>> else
>> xprt_free_bc_request(req);
>> }
>> I mean that in step 1, xprt was only released, but
>> xprt_wake_up_backlog was not called (I don’t know if it is necessary,
>> but xprt->state may still be XPRT_CONGESTED), which causes xprt to
>> hold up. I think it happens when the task that does not hold a slot
>> is the last released task，xprt_wake_up_backlog(clear XPRT_CONGESTED)
>> will not be executed. :-)
>> Thanks，
>> Bixuan Cui
>>
>>
> My point is that in that case 1, there is no slot to free, so there is
> no change to the congestion state.
>
> IOW: your patch is incorrect because it is trying to assign a slot in a
> case where there is no slot to assign.
Hi，
I found the correct way to fix it, that is, do not free the request when
there are tasks in the xprt->backlog :-)
And it has been fixed by e877a88d1f06 (SUNRPC in case of backlog, hand
free slots directly to waiting task)
commit e877a88d1f069edced4160792f42c2a8e2dba942
Author: NeilBrown <[email protected]>
Date: Mon May 17 09:59:10 2021 +1000
SUNRPC in case of backlog, hand free slots directly to waiting task
If sunrpc.tcp_max_slot_table_entries is small and there are tasks
on the backlog queue, then when a request completes it is freed and the
first task on the queue is woken. The expectation is that it will wake
and claim that request. However if it was a sync task and the waiting
process was killed at just that moment, it will wake and NOT claim the
request.
Thanks for your advice.
Thanks,
Bixuan Cui