Bug 95561

Summary: nfsv4.1-svc hangs and causes an unclean suspend
Product: File System Reporter: Bjoern Franke (bjo)
Component: NFSAssignee: Trond Myklebust (trondmy)
Status: NEW ---    
Severity: normal CC: bfields, daniel, eric, fche, linux, matti.niemenmaa+kernelbugs, mikkeloscar, mjevans1983, szg00000
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: >=3.19.2, >=3.14.36 Subsystem:
Regression: No Bisected commit-id:

Description Bjoern Franke 2015-03-25 11:30:54 UTC
Trying to suspend fails to a hanging nfsv4.1-svc:

[  242.963957] PM: Syncing filesystems ... done.
[  243.535088] PM: Preparing system for mem sleep
[  243.730776] Freezing user space processes ... (elapsed 0.002 seconds) done.
[  243.733034] Freezing remaining freezable tasks ... 
[  263.736906] Freezing of tasks failed after 20.007 seconds (1 tasks refusing to freeze, wq_busy=0):
[  263.737154] nfsv4.1-svc     D ffff8800a0fd7d78     0   951      2 0x00000000
[  263.737165]  ffff8800a0fd7d78 ffff8800a0f66d50 0000000000013f00 ffff8800a0fd7fd8
[  263.737174]  0000000000013f00 ffff88012af86d50 ffff8800a0f66d50 ffffffffa0298aa0
[  263.737181]  ffff8800a0d70000 ffffffffa0298aa0 0000000000000000 ffff8800a0fd7cd8
[  263.737188] Call Trace:
[  263.737239]  [<ffffffffa0298aa0>] ? rpc_destroy_wait_queue+0x20/0x20 [sunrpc]
[  263.737262]  [<ffffffffa0298aa0>] ? rpc_destroy_wait_queue+0x20/0x20 [sunrpc]
[  263.737282]  [<ffffffffa0298654>] ? rpc_release_resources_task+0x34/0x40 [sunrpc]
[  263.737301]  [<ffffffffa02997b8>] ? __rpc_execute+0x2c8/0x4a0 [sunrpc]
[  263.737313]  [<ffffffff810db9bb>] ? lock_timer_base.isra.37+0x2b/0x50
[  263.737323]  [<ffffffff8155e999>] schedule+0x29/0x70
[  263.737332]  [<ffffffff8156144b>] schedule_timeout+0x11b/0x250
[  263.737340]  [<ffffffff810db360>] ? migrate_timer_list+0xd0/0xd0
[  263.737362]  [<ffffffffa083e1ba>] nfs41_callback_svc+0x1aa/0x1e0 [nfsv4]
[  263.737369]  [<ffffffff810b4380>] ? wait_woken+0x90/0x90
[  263.737387]  [<ffffffffa083e010>] ? nfs4_callback_svc+0x60/0x60 [nfsv4]
[  263.737396]  [<ffffffff81091748>] kthread+0xd8/0xf0
[  263.737404]  [<ffffffff81091670>] ? kthread_create_on_node+0x1c0/0x1c0
[  263.737412]  [<ffffffff81562758>] ret_from_fork+0x58/0x90
[  263.737419]  [<ffffffff81091670>] ? kthread_create_on_node+0x1c0/0x1c0

The issue also occurs with 4.0rc5 and didn't occur with 3.19.1.
Maybe it's related to 0c0f2544c2355899dcf62821ed0b230b60b79c22
Comment 1 Bjoern Franke 2015-03-26 22:31:27 UTC
Also affected: 3.19.3, 3.14.36 / 3.14.37.
Comment 2 Bjoern Franke 2015-03-26 22:40:31 UTC
According to https://forum.manjaro.org/index.php?topic=21508.0 downgrading nfs-utils to 1.3.1-1 fixes the problem.
Comment 3 Eric Benoit 2015-03-30 23:11:16 UTC
I too have encountered this issue, but noticed it not when attempting a suspend, but merely by the fact that my load averages at idle are now 1.00 1.00 1.00.

I also noticed nfsv4.1-svc stuck in D state:

  PID TTY      STAT   TIME  MAJFL   TRS   DRS   RSS %MEM COMMAND
 2267 ?        D      0:00      0     0     0     0  0.0 [nfsv4.1-svc]

It does indeed seem to be related to the aforementioned commit. I reverted that patch against 3.19.3 and it resolved the issue. It's still present in 4.0-rc6.

I can also confirm that downgrading nfs-utils to 1.3.1 (from 1.3.2) also resolves the issue.
Comment 4 Michael Evans 2015-05-07 09:27:22 UTC
As this issue might be causing my issues suspending/hibernating while NFS mounts exist I'm trying to understand the logic of the suspected commit.

Is it valid to call schedule_timeout (with any value) before calling finish_wait; which is what I presume is closing the critical section?


Previously bjo@nord-west.org 2015-03-25 11:30:54 UTC referenced:

http://kernel.suse.com/cgit/kernel/commit/?h=stable&id=0c0f2544c2355899dcf62821ed0b230b60b79c22

This patch is trying to convert the logic from incorrectly flagged interruptable operations to an un-interruptable logic, therefore I cannot assume that the ordering of operations it modifies is also valid.

 		} else {
 			spin_unlock_bh(&serv->sv_cb_lock);
-			schedule();
+			/* schedule_timeout to game the hung task watchdog */
+			schedule_timeout(60 * HZ);
+			finish_wait(&serv->sv_cb_waitq, &wq);
 		}
-		finish_wait(&serv->sv_cb_waitq, &wq);
Comment 5 Mikkel Oscar Lyderik 2015-05-08 19:30:47 UTC
Setting the value Defaultvers=4.0 in /etc/nfsmount.conf as recommended here: https://bugs.archlinux.org/task/44323#comment134552 also solves this problem for me (with nfs-utils 1.3.2).
Comment 6 Michael Evans 2015-05-12 04:30:13 UTC
(In reply to Mikkel Oscar Lyderik from comment #5)
> Setting the value Defaultvers=4.0 in /etc/nfsmount.conf as recommended here:
> https://bugs.archlinux.org/task/44323#comment134552 also solves this problem
> for me (with nfs-utils 1.3.2).

That is a *workaround* not a solution.
Comment 7 bfields 2015-06-10 15:12:41 UTC
Was this fixed by 5d05e54af3cd "nfs: fix high load average due to callback thread sleeping" (went into 4.1-rc1)?