1

I'm somewhat new when it comes to administering Linux and NFS, so please bear with me.

We are trying to setup a small cluster at work. Currently the system is just 2 DELL high-end workstations, running CentOS 6.5. To make administering users and files easier, we have decided to share via NFS the /home directory, and four files from /etc (passwd, group, shadow, and gshadow (This is done by moving them to a sub-directory, and using links to put them back in /etc))

The files are shared with this in /etc/exports on the server:

/home/  x.x.x.0/24(rw,sync,no_root_squash,no_all_squash)  
/etc/sub_dir/   x.x.x.0/24(rw,sync,no_root_squash,no_all_squash)

The files are mounted with this in /etc/fstab on the client:

server_name:/home/          /home/          nfs rw,sync,hard,intr 0 0
server_name:/etc/sub_dir/           /etc/sub_dir/           nfs rw,sync,hard,intr 0 0

After setting all this up, the system worked fine for about a month. As long as the server was on, when the client started all the server's users were visible, and as well were all the files.

However, about 5 days ago, it started to act up. After starting the client, it would work fine for about 15 minutes (give or take). The users could log on locally or via SSH. After that first 15 minutes, the system would almost totally lock up. New users couldn't log in, and logged in users couldn't do anything. (Basic things like moving the mouse still work). Only way to get the system going again is to turn the client off and back on. Unfortunately, this also means debugging on the client is very difficult.

We have narrowed down the problem to have something to do with the NFS shares of the files described above. (We know this because disabling the mounts in /etc/fstab allows the client to go back to it's own local files, and everything works fine)

The farthest we can figure is the system starts, mounts everything, and works. Then, the connections drop, and the next time the client needs access to a file (for example, passwd) it can't find it, and the system hangs waiting for the connection.

The computers are on the same 1000 Mbps switch, and the load is fairly light.

Any help would be much appreciated.

UPDATES:

I have been doing some more digging. I found this similar issue here on Server Fault, but it too is unresolved.
I have also tried switching to UDP, but that also didn't solve the issue.
I came across articles explaining how to find and solve NFS being stale (but I'm not sure that's the issue).

UPDATES:

I managed to get a log from the client from /var/log/messages (during a few minutes of operation).
Looking through it, I found a repeating pattern of nfsidmap being "blocked", then a Call Trace with lots of "[nfs]" entries in it.

Aug  7 14:17:01 computer-name kernel: INFO: task crond:10578 blocked for more than 120 seconds.
Aug  7 14:17:01 computer-name kernel:      Tainted: P           ---------------    2.6.32-431.20.3.el6.x86_64 #1
Aug  7 14:17:01 computer-name kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug  7 14:17:01 computer-name kernel: crond         D 000000000000000e     0 10578      1 0x00000080
Aug  7 14:17:01 computer-name kernel: ffff880a5cf0b148 0000000000000082 0000000000000000 ffffffff81059096
Aug  7 14:17:01 computer-name kernel: ffff880a5cf0b0d8 ffff880a5f77eaa0 ffff880a5cf0b0d8 ffffffff8105559d
Aug  7 14:17:01 computer-name kernel: ffff880a555a5098 ffff880a5cf0bfd8 000000000000fbc8 ffff880a555a5098
Aug  7 14:17:01 computer-name kernel: Call Trace:
Aug  7 14:17:01 computer-name kernel: [<ffffffff81059096>] ? enqueue_task+0x66/0x80
Aug  7 14:17:01 computer-name kernel: [<ffffffff8105559d>] ? check_preempt_curr+0x6d/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff815296d5>] schedule_timeout+0x215/0x2e0
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109afb6>] ? autoremove_wake_function+0x16/0x40
Aug  7 14:17:01 computer-name kernel: [<ffffffff810546b9>] ? __wake_up_common+0x59/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff81529353>] wait_for_common+0x123/0x180
Aug  7 14:17:01 computer-name kernel: [<ffffffff81061d00>] ? default_wake_function+0x0/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff81095211>] ? __queue_work+0x41/0x50
Aug  7 14:17:01 computer-name kernel: [<ffffffff8152946d>] wait_for_completion+0x1d/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109386c>] call_usermodehelper_exec+0x10c/0x120
Aug  7 14:17:01 computer-name kernel: [<ffffffff812246ae>] call_sbin_request_key+0x24e/0x2f0
Aug  7 14:17:01 computer-name kernel: [<ffffffff8121eb03>] ? key_instantiate_and_link+0xa3/0xb0
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1060030>] ? nfs4_callback_layoutrecall+0x30/0x90 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffff812241e5>] request_key_and_link+0x315/0x3d0
Aug  7 14:17:01 computer-name kernel: [<ffffffff812243b0>] request_key+0x50/0xa0
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105cb65>] nfs_idmap_request_key+0xc5/0x170 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105d194>] nfs_idmap_lookup_id+0x34/0x80 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105d5d5>] nfs_map_name_to_uid+0x75/0xa0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057504>] decode_getfattr_attrs+0xf64/0xfa0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffff810097cc>] ? __switch_to+0x1ac/0x320
Aug  7 14:17:01 computer-name kernel: [<ffffffffa10575c3>] decode_getfattr_generic.clone.0+0x83/0xe0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057ce0>] nfs4_xdr_dec_access+0xb0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057c30>] ? nfs4_xdr_dec_access+0x0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f90fc4>] rpcauth_unwrap_resp+0x84/0xb0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057c30>] ? nfs4_xdr_dec_access+0x0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f85923>] call_decode+0x1b3/0x800 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109b020>] ? wake_bit_function+0x0/0x50
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f85770>] ? call_decode+0x0/0x800 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f8f677>] __rpc_execute+0x77/0x350 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109ae27>] ? bit_waitqueue+0x17/0xd0
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f8f9b1>] rpc_execute+0x61/0xa0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f863a5>] rpc_run_task+0x75/0x90 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f864c2>] rpc_call_sync+0x42/0x70 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104ba9e>] _nfs4_call_sync+0x3e/0x40 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104a7cc>] _nfs4_proc_access+0x11c/0x1a0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104a89b>] nfs4_proc_access+0x4b/0x80 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa102658c>] nfs_do_access+0x19c/0x240 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f92625>] ? generic_lookup_cred+0x15/0x20 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f915f0>] ? rpcauth_lookupcred+0x70/0xc0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa10266d8>] nfs_permission+0xa8/0x1e0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffff81198e93>] __link_path_walk+0xb3/0x1000
Aug  7 14:17:01 computer-name kernel: [<ffffffff81199abf>] __link_path_walk+0xcdf/0x1000
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119a09a>] path_walk+0x6a/0xe0
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119a2ab>] filename_lookup+0x6b/0xc0
Aug  7 14:17:01 computer-name kernel: [<ffffffff81226c26>] ? security_file_alloc+0x16/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119b784>] do_filp_open+0x104/0xd20
Aug  7 14:17:01 computer-name kernel: [<ffffffff8128f70a>] ? strncpy_from_user+0x4a/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff811a8a62>] ? alloc_fd+0x92/0x160
Aug  7 14:17:01 computer-name kernel: [<ffffffff81185ba9>] do_sys_open+0x69/0x140
Aug  7 14:17:01 computer-name kernel: [<ffffffff81185cc0>] sys_open+0x20/0x30
Aug  7 14:17:01 computer-name kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b
Aug  7 14:17:01 computer-name kernel: INFO: task nfsidmap:13767 blocked for more than 120 seconds.
Aug  7 14:17:01 computer-name kernel:      Tainted: P           ---------------    2.6.32-431.20.3.el6.x86_64 #1
Aug  7 14:17:01 computer-name kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Aug  7 14:17:01 computer-name kernel: nfsidmap      D 000000000000000e     0 13767  13766 0x00000080
Aug  7 14:17:01 computer-name kernel: ffff88145d1e93f8 0000000000000086 0000000000000000 ffff880a5bae6080
Aug  7 14:17:01 computer-name kernel: ffff88145d1e9378 ffffffff814b1d35 0000000053e3c1ad 0000000028930cb7
Aug  7 14:17:01 computer-name kernel: ffff88145139f058 ffff88145d1e9fd8 000000000000fbc8 ffff88145139f058
Aug  7 14:17:01 computer-name kernel: Call Trace:
Aug  7 14:17:01 computer-name kernel: [<ffffffff814b1d35>] ? tcp_event_new_data_sent+0xb5/0x110
Aug  7 14:17:01 computer-name kernel: [<ffffffff81223d90>] ? key_wait_bit+0x0/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff81223d9e>] key_wait_bit+0xe/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff81529a8f>] __wait_on_bit+0x5f/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff81223d90>] ? key_wait_bit+0x0/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff81529b38>] out_of_line_wait_on_bit+0x78/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109b020>] ? wake_bit_function+0x0/0x50
Aug  7 14:17:01 computer-name kernel: [<ffffffff81223d7e>] wait_for_key_construction+0x6e/0x80
Aug  7 14:17:01 computer-name kernel: [<ffffffff812243c5>] request_key+0x65/0xa0
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105cb65>] nfs_idmap_request_key+0xc5/0x170 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105d194>] nfs_idmap_lookup_id+0x34/0x80 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa105d5d5>] nfs_map_name_to_uid+0x75/0xa0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057504>] decode_getfattr_attrs+0xf64/0xfa0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffff810097cc>] ? __switch_to+0x1ac/0x320
Aug  7 14:17:01 computer-name kernel: [<ffffffffa10575c3>] decode_getfattr_generic.clone.0+0x83/0xe0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057ce0>] nfs4_xdr_dec_access+0xb0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057c30>] ? nfs4_xdr_dec_access+0x0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f90fc4>] rpcauth_unwrap_resp+0x84/0xb0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa1057c30>] ? nfs4_xdr_dec_access+0x0/0xc0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f85923>] call_decode+0x1b3/0x800 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109b020>] ? wake_bit_function+0x0/0x50
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f85770>] ? call_decode+0x0/0x800 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f8f677>] __rpc_execute+0x77/0x350 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffff8109ae27>] ? bit_waitqueue+0x17/0xd0
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f8f9b1>] rpc_execute+0x61/0xa0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f863a5>] rpc_run_task+0x75/0x90 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f864c2>] rpc_call_sync+0x42/0x70 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104ba9e>] _nfs4_call_sync+0x3e/0x40 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104a7cc>] _nfs4_proc_access+0x11c/0x1a0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa104a89b>] nfs4_proc_access+0x4b/0x80 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa102658c>] nfs_do_access+0x19c/0x240 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f92625>] ? generic_lookup_cred+0x15/0x20 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa0f915f0>] ? rpcauth_lookupcred+0x70/0xc0 [sunrpc]
Aug  7 14:17:01 computer-name kernel: [<ffffffffa10266d8>] nfs_permission+0xa8/0x1e0 [nfs]
Aug  7 14:17:01 computer-name kernel: [<ffffffff81198e93>] __link_path_walk+0xb3/0x1000
Aug  7 14:17:01 computer-name kernel: [<ffffffff81199abf>] __link_path_walk+0xcdf/0x1000
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119a09a>] path_walk+0x6a/0xe0
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119a2ab>] filename_lookup+0x6b/0xc0
Aug  7 14:17:01 computer-name kernel: [<ffffffff81226c26>] ? security_file_alloc+0x16/0x20
Aug  7 14:17:01 computer-name kernel: [<ffffffff8119b784>] do_filp_open+0x104/0xd20
Aug  7 14:17:01 computer-name kernel: [<ffffffff811a27e8>] ? d_free+0x58/0x60
Aug  7 14:17:01 computer-name kernel: [<ffffffff8128f70a>] ? strncpy_from_user+0x4a/0x90
Aug  7 14:17:01 computer-name kernel: [<ffffffff811a8a62>] ? alloc_fd+0x92/0x160
Aug  7 14:17:01 computer-name kernel: [<ffffffff81185ba9>] do_sys_open+0x69/0x140
Aug  7 14:17:01 computer-name kernel: [<ffffffff81185cc0>] sys_open+0x20/0x30
Aug  7 14:17:01 computer-name kernel: [<ffffffff8100b072>] system_call_fastpath+0x16/0x1b

(Sorry about the length, I have no idea what parts are useful)
This pattern repeats every two minutes.

According to this and this, the message indicates that there is some kind of resource starvation. However, the client is typically idle.

Improve this question

2 Answers 2

Reset to default
5

The kernel error messages indicate it was not able to schedule a process to run for 120 seconds. It's either extreme high CPU usage or contention at the I/O level.

I would recommend against using NFS to share system critical files like /etc/passwd or even symlinks because the very NFS operations is dependent on them. You could think about setting up a script to transfer them via SCP and overwrite the current ones, but then you've to think about the logic to determine which server has the newer files.

The long-term solution would be to adopt LDAP.

EDIT: based on additional information provided in comments, changing from NFSv4 to NFSv3 is an alternative.

Improve this answer
4
  • I recognize that sharing out 'those four files' seems a bit flaky; and if it never worked at all, I would agree and look for another way of synchronizing user accounts across system. But the baffling thing is that it worked OK for about a month, exactly as expected.
    – Maculin
    Aug 13, 2014 at 13:59
  • I can related to that. Personally I have only seen that "120 seconds" messages when our servers reached 100% memory AND cpu utilization. Things got so out of control that the out-of-memory killer (OOM) couldn't even run correctly (probably due to the schedule not being able to schedule anything, even kernel threads). Another possible root cause are copies of huge files over NFS, do you know if that is happening sporadicaly? Additionally, can you try switching to NFS v3? And last question, look for message like "nfs server not responding" in the logs.
    – Giovanni Tirloni
    Aug 13, 2014 at 14:57
  • 1
    The timing was quite predictable, always 10-15 minutes after start. Usually just 10. Never saw messages like "nfs server not responding" in the logs. And I have tried NFS 3, and now it works! That actually may be what fixed it. Thanks!
    – Maculin
    Aug 13, 2014 at 19:23
  • Awesome! Updated answer to reflect new info.
    – Giovanni Tirloni
    Aug 13, 2014 at 20:52
1

I started just trying stuff, and I seem to have stumbled on the answer.

On the client, the line for mounting the passwd, group, shadow, and gshadow files in /etc/fstab was like this:

server_name:/etc/sub_dir/           /etc/sub_dir/           nfs rw,sync,hard,intr 0 0

I have changed it to this:

server_name:/etc/sub_dir/           /etc/sub_dir/           nfs ro,sync,hard,intr,nolock,noexec,noacl,nfsvers=3 0 0

The changes are:

  • Changed rw to ro
  • Added nolock
  • Added noexec
  • Added noacl
  • Added nfsvers=3 (This was also suggested by gtirloni above, thanks!)

After that, rebooted the client, and everything seems to be OK. Client has been up for over 40 minutes, and everything is fine (the problem would show up 10 - 15 minutes after startup, so 40 minutes is a record).

Since I changed 5 things at once, I'm not sure which fixed it (I suspect it was either the nolock or the nfsvers=3). Also, I still have no idea why it worked fine for about a month, then decided to be difficult.

Improve this answer
1
  • Did you by chance check to see if an automatic update changed your kernel on either system? Is it possible the lock daemon on the server was FUBARd? Now, NFS4 locking is different than NFS3, so frankly, I don't know what I'm talking about. If you feel lucky someday, remove nolock to see what impact that has. The other options will have done almost nothing.
    – Otheus
    Mar 21, 2016 at 14:41

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.