I have been trying to track down a problem with my diskless nodes that mount their root filesystems over NFS. The base OS is Centos 5.1, but we have replaced the kernel with a stock linux-2.6.22.19. We have two sets of nodes, one set which have 4 cores (dual socket Woodcrest and one set that has 8 cores (dual socket Harpertown). The reason I bring this up is that the number of hangs we get on the Harpertown nodes is about an order-of-magnitude more than hangs on the Woodcrest nodes. It is a hard bug to reliably trigger, so the hangs could be a function of the jobs run more than a race condition that happens when a system has more cores. When a node hangs, it is typically pingable. I know that processes are still running because I can get messages through syslogd and other processes communicate (Grid Engine Daemon). From SysRq, I see the following process blocked: Sep 18 15:34:27 h66 kernel: SysRq : Show Blocked State Sep 18 15:34:27 h66 kernel: Sep 18 15:34:27 h66 kernel: free sibling Sep 18 15:34:27 h66 kernel: task PC stack pid father child younger older Sep 18 15:34:27 h66 kernel: automount D ffff810011c62a20 0 7115 1 (NOTLB) Sep 18 15:34:27 h66 kernel: ffff810267c87b18 0000000000000046 0000000000000000 0000000000000000 Sep 18 15:34:27 h66 kernel: ffff810267c87a98 ffff8101f4e382c0 ffff81042fc9d560 000000000000045e Sep 18 15:34:27 h66 kernel: ffff8101f4e38470 000000018022827d 0000000104f26361 000000002f806ec0 Sep 18 15:34:27 h66 kernel: Call Trace: Sep 18 15:34:27 h66 kernel: [<ffffffff804994f2>] wait_for_completion+0xb2/0x100 Sep 18 15:34:27 h66 kernel: [<ffffffff802286c0>] default_wake_function+0x0/0x10 Sep 18 15:34:27 h66 kernel: [<ffffffff8023ebb0>] flush_cpu_workqueue+0x50/0x80 Sep 18 15:34:27 h66 kernel: [<ffffffff8023eca0>] wq_barrier_func+0x0/0x10 Sep 18 15:34:27 h66 kernel: [<ffffffff8023f203>] flush_workqueue+0x43/0x60 Sep 18 15:34:27 h66 kernel: [<ffffffff804893da>] __rpc_execute+0x6a/0x270 Sep 18 15:34:27 h66 kernel: Sep 18 15:34:27 h66 kernel: Call Trace: Sep 18 15:34:27 h66 kernel: [<ffffffff802fa185>] nfs_file_write+0x185/0x1f0 Sep 18 15:34:27 h66 kernel: Sep 18 15:34:27 h66 kernel: 0000000000000000 ffff8101a14d2380 ffff81042fd275e0 000000000000188a Sep 18 15:34:27 h66 kernel: Call Trace: Sep 18 15:34:27 h66 kernel: [<ffffffff8021bd7c>] do_page_fault+0x1fc/0x830 Sep 18 15:34:27 h66 kernel: Here is another example of automounter blocking, but it seems to show a deeper call tree: Sep 18 19:24:54 h32 kernel: free sibling Sep 18 19:24:54 h32 kernel: task PC stack pid father child younger older Sep 18 19:24:54 h32 kernel: automount D ffff8102e09d3ba0 0 24707 1 (NOTLB) Sep 18 19:24:54 h32 kernel: ffff8102e09d3b18 0000000000000046 0000000000000000 ffffffff80225cdc Sep 18 19:24:54 h32 kernel: ffff8102e09d3a98 ffff81041571e8a0 ffff81042f057760 0000000000003a12 Sep 18 19:24:54 h32 kernel: ffff81041571ea50 000000078022827d ffff81042cf3b9c8 000000002e95be80 Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff80225cdc>] task_rq_lock+0x4c/0x90 Sep 18 19:24:54 h32 kernel: [<ffffffff804994f2>] wait_for_completion+0xb2/0x100 Sep 18 19:24:54 h32 kernel: [<ffffffff802286c0>] default_wake_function+0x0/0x10 Sep 18 19:24:54 h32 kernel: [<ffffffff8023ebb0>] flush_cpu_workqueue+0x50/0x80 Sep 18 19:24:54 h32 kernel: [<ffffffff8023eca0>] wq_barrier_func+0x0/0x10 Sep 18 19:24:54 h32 kernel: [<ffffffff8023f203>] flush_workqueue+0x43/0x60 Sep 18 19:24:54 h32 kernel: [<ffffffff80305031>] nfs3_proc_getattr+0x51/0x90 Sep 18 19:24:54 h32 kernel: [<ffffffff8027ee13>] vfs_lstat_fd+0x43/0x70 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: 0000000000000000 ffff81031a1a0080 ffff81042fd5d620 0000000000005eec Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff80256e78>] sync_page+0x38/0x50 Sep 18 19:24:54 h32 kernel: [<ffffffff802599ba>] generic_file_aio_read+0xda/0x170 Sep 18 19:24:54 h32 kernel: [<ffffffff8027be05>] vfs_read+0xc5/0x160 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: ffff8103673a1bb8 ffff810421f88a20 ffff81042fd275e0 000000000000217b Sep 18 19:24:54 h32 kernel: ffff810421f88bd0 0000000380256d1d 00000001017e837a 00000000673a1ba8 Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff80499e2a>] __wait_on_bit_lock+0x4a/0x80 Sep 18 19:24:54 h32 kernel: [<ffffffff80256e1f>] __lock_page+0x5f/0x70 Sep 18 19:24:54 h32 kernel: [<ffffffff802fb344>] nfs_invalidate_mapping_nolock+0x24/0xf0 Sep 18 19:24:54 h32 kernel: [<ffffffff802fc5a9>] nfs_revalidate_mapping+0xd9/0xe0 Sep 18 19:24:54 h32 kernel: [<ffffffff8028cdd1>] fcntl_setlk+0x71/0x2c0 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: 0000000000000000 ffff81042d275720 ffff81042fcd35a0 000000000000134f Sep 18 19:24:54 h32 kernel: ffff81042d2758d0 0000000200000001 00000001017e900d 0000000000000780 Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff8049a25a>] __mutex_lock_slowpath+0x6a/0xb0 Sep 18 19:24:54 h32 kernel: [<ffffffff802fc567>] nfs_revalidate_mapping+0x97/0xe0 Sep 18 19:24:54 h32 kernel: [<ffffffff8049b3e9>] _spin_unlock_irq+0x9/0x10 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: ffff81023b9d7cf8 0000000000000046 0000000000000000 0000000000000000 Sep 18 19:24:54 h32 kernel: 0000000000000000 ffff81042194ab20 ffff81042fd5d620 00000000000015f0 Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff8049a0a2>] mutex_lock+0x22/0x30 Sep 18 19:24:54 h32 kernel: [<ffffffff8028cdd1>] fcntl_setlk+0x71/0x2c0 Sep 18 19:24:54 h32 kernel: [<ffffffff8049b3e9>] _spin_unlock_irq+0x9/0x10 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: sshd D ffff810011c86a20 0 24440 3686 (NOTLB) Sep 18 19:24:54 h32 kernel: ffff810309d69cf8 0000000000000046 0000000000000000 0000000000000000 Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff8049b3f9>] _read_unlock_irq+0x9/0x10 Sep 18 19:24:54 h32 kernel: [<ffffffff802fb308>] nfs_zap_caches+0x28/0x40 Sep 18 19:24:54 h32 kernel: [<ffffffff80209b6e>] system_call+0x7e/0x83 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff8049a25a>] __mutex_lock_slowpath+0x6a/0xb0 Sep 18 19:24:54 h32 kernel: [<ffffffff8049b3f9>] _read_unlock_irq+0x9/0x10 Sep 18 19:24:54 h32 kernel: [<ffffffff8027b4e9>] do_sync_read+0xd9/0x120 Sep 18 19:24:54 h32 kernel: [<ffffffff8027c2e3>] sys_read+0x53/0x90 Sep 18 19:24:54 h32 kernel: Sep 18 19:24:54 h32 kernel: ffff8101fe8c1cf8 0000000000000046 0000000000000000 0000000000000000 Sep 18 19:24:54 h32 kernel: 0000000000000000 ffff8101ee13f620 ffff81042fd5d620 0000000000000dca Sep 18 19:24:54 h32 kernel: Call Trace: Sep 18 19:24:54 h32 kernel: [<ffffffff8028cdd1>] fcntl_setlk+0x71/0x2c0 Sep 18 19:24:54 h32 kernel: Other processes get stuck. These include sshd, udevd, agetty, and init. Automounter seems to be the common thread. Also, since the problem looked like NFS, I turned on both rpc_debug and nfs_debug on all nodes. When I did this, I was not able trigger a failure. The only filesystems that are managed by automounter is /home (no timeout specified, so it is 600 seconds). Any advice on how to proceed debugging this would be appreciated. Thanks, Craig -- Craig Tierney (craig.tierney@xxxxxxxx) -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
