* Re: session hangs with 2.6.33rc7 & nfs-utils 1.2.2rc9 [not found] ` <1265998794.2832.23.camel@localhost> @ 2010-05-06 15:40 ` Timo Aaltonen [not found] ` <alpine.DEB.2.00.1005061730460.3282-9o+TK994UVukEuhtYYxXtw@public.gmane.org> 0 siblings, 1 reply; 4+ messages in thread From: Timo Aaltonen @ 2010-05-06 15:40 UTC (permalink / raw) To: linux-nfs; +Cc: Jeff Layton, Trond Myklebust Reviving the old thread, since it's still happening. Maybe I should file a proper bug about this? On Fri, 12 Feb 2010, Trond Myklebust wrote: > On Fri, 2010-02-12 at 11:13 -0500, Jeff Layton wrote: >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] 130.233.227.1 D 00000000ffffffff 0 29902 2 0x00000080 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] ffff8800c158dc50 0000000000000046 0000000000015ac0 0000000000015ac0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] ffff880116251ab0 ffff8800c158dfd8 0000000000015ac0 ffff8801162516f0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] 0000000000015ac0 ffff8800c158dfd8 0000000000015ac0 ffff880116251ab0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] Call Trace: >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec20>] ? rpc_wait_bit_killable+0x0/0x40 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec44>] rpc_wait_bit_killable+0x24/0x40 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8155f05f>] __wait_on_bit+0x5f/0x90 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec20>] ? rpc_wait_bit_killable+0x0/0x40 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8155f108>] out_of_line_wait_on_bit+0x78/0x90 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81083640>] ? wake_bit_function+0x0/0x40 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09ff555>] __rpc_execute+0x105/0x220 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09ff696>] rpc_execute+0x26/0x30 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09f7b8a>] rpc_run_task+0x3a/0x90 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09f7ce2>] rpc_call_sync+0x42/0x70 [sunrpc] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81055080>] ? finish_task_switch+0x50/0xd0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0baa0ed>] nfs4_proc_renew+0x4d/0xa0 [nfs] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb61fc>] nfs4_check_lease+0x8c/0xc0 [nfs] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6fa0>] ? nfs4_run_state_manager+0x0/0x40 [nfs] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6e98>] nfs4_state_manager+0xf8/0x200 [nfs] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff810672ed>] ? allow_signal+0x9d/0xb0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6fc3>] nfs4_run_state_manager+0x23/0x40 [nfs] >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81083286>] kthread+0x96/0xa0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8101422a>] child_rip+0xa/0x20 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff810831f0>] ? kthread+0x0/0xa0 >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81014220>] ? child_rip+0x0/0x20 >> >> Here, the mount appears to be attempting to renew the state. >> >> <wild ass speculation> >> Another thread (not shown in the sysrq-t) is attempting to do writeback >> (maybe the bdev flush thread?) and that's in turn blocked by the state >> recovery code? >> </wild ass speculation> >> >> Looking back over the capture that you sent originally, I see that the >> client is attempting a WRITE, getting a NFS4ERR_BAD_STATEID back from >> the server, issuing a RENEW which succeeds and then reattempting the >> WRITE. >> >> Trond, shouldn't it be trying to recover the state before reissuing the >> write? >> > > Yes. Both nfs4_read_done() and nfs4_write_done() will call > nfs4_async_handle_error(), which again should call > nfs4_state_mark_reclaim_nograce() on the stateid. The state manager > should then end up recovering that stateid before the write is > reattempted. > > We did previously have an issue if the server were to return > NFS4ERR_STALE_STATEID, followed by NFS4ERR_OK to our RENEW probe > (==seriously buggy server), but 2.6.33-rc7 has a fix for that. The offending app seems to be the new "indicator-applet" on the Ubuntu GNOME desktop, so maybe that's why others haven't seen this bug yet? Here's the trace from dmesg: [482400.730245] INFO: task indicator-apple:28782 blocked for more than 120 seconds. [482400.730247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [482400.730249] indicator-app D 0000000000000000 0 28782 1 0x00000080 [482400.730253] ffff880010579ac8 0000000000000082 0000000000015bc0 0000000000015bc0 [482400.730257] ffff880109bb1ab0 ffff880010579fd8 0000000000015bc0 ffff880109bb16f0 [482400.730261] 0000000000015bc0 ffff880010579fd8 0000000000015bc0 ffff880109bb1ab0 [482400.730265] Call Trace: [482400.730275] [<ffffffffa0b6b2b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs] [482400.730279] [<ffffffff8153eb57>] io_schedule+0x47/0x70 [482400.730288] [<ffffffffa0b6b2be>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs] [482400.730292] [<ffffffff8153f3af>] __wait_on_bit+0x5f/0x90 [482400.730302] [<ffffffffa0b6b2b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs] [482400.730305] [<ffffffff8153f458>] out_of_line_wait_on_bit+0x78/0x90 [482400.730309] [<ffffffff81085360>] ? wake_bit_function+0x0/0x40 [482400.730318] [<ffffffffa0b6b29f>] nfs_wait_on_request+0x2f/0x40 [nfs] [482400.730329] [<ffffffffa0b6f6af>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs] [482400.730340] [<ffffffffa0b70aee>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs] [482400.730350] [<ffffffffa0b70ed9>] nfs_write_mapping+0x79/0xb0 [nfs] [482400.730361] [<ffffffffa0b70f47>] nfs_wb_all+0x17/0x20 [nfs] [482400.730369] [<ffffffffa0b5feba>] nfs_do_fsync+0x2a/0x60 [nfs] [482400.730378] [<ffffffffa0b608b6>] nfs_file_write+0x106/0x1e0 [nfs] [482400.730381] [<ffffffff8114270a>] do_sync_write+0xfa/0x140 [482400.730385] [<ffffffff81085320>] ? autoremove_wake_function+0x0/0x40 [482400.730389] [<ffffffff81250b96>] ? security_file_permission+0x16/0x20 [482400.730392] [<ffffffff81142a08>] vfs_write+0xb8/0x1a0 [482400.730396] [<ffffffff810c03e2>] ? audit_syscall_entry+0x242/0x270 [482400.730399] [<ffffffff811432a1>] sys_write+0x51/0x80 [482400.730403] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b I haven't tried the 2.6.34-series yet.. -- Timo Aaltonen Systems Specialist IT Services, Aalto University ^ permalink raw reply [flat|nested] 4+ messages in thread
[parent not found: <alpine.DEB.2.00.1005061730460.3282-9o+TK994UVukEuhtYYxXtw@public.gmane.org>]
* Re: session hangs with 2.6.33rc7 & nfs-utils 1.2.2rc9 [not found] ` <alpine.DEB.2.00.1005061730460.3282-9o+TK994UVukEuhtYYxXtw@public.gmane.org> @ 2010-05-06 16:57 ` Trond Myklebust 2010-05-14 6:43 ` Timo Aaltonen 0 siblings, 1 reply; 4+ messages in thread From: Trond Myklebust @ 2010-05-06 16:57 UTC (permalink / raw) To: Timo Aaltonen; +Cc: linux-nfs, Jeff Layton On Thu, 2010-05-06 at 18:40 +0300, Timo Aaltonen wrote: > Reviving the old thread, since it's still happening. Maybe I should file a > proper bug about this? Please do. Can you see if you can get a trace of the recovery thread? Also, please check your dmesg log for any 'unhandled error' messages. If there is nothing there, then we may have to get a 'wireshark' trace too... Cheers Trond > On Fri, 12 Feb 2010, Trond Myklebust wrote: > > > On Fri, 2010-02-12 at 11:13 -0500, Jeff Layton wrote: > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] 130.233.227.1 D 00000000ffffffff 0 29902 2 0x00000080 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] ffff8800c158dc50 0000000000000046 0000000000015ac0 0000000000015ac0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] ffff880116251ab0 ffff8800c158dfd8 0000000000015ac0 ffff8801162516f0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] 0000000000015ac0 ffff8800c158dfd8 0000000000015ac0 ffff880116251ab0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] Call Trace: > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec20>] ? rpc_wait_bit_killable+0x0/0x40 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec44>] rpc_wait_bit_killable+0x24/0x40 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8155f05f>] __wait_on_bit+0x5f/0x90 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09fec20>] ? rpc_wait_bit_killable+0x0/0x40 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8155f108>] out_of_line_wait_on_bit+0x78/0x90 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81083640>] ? wake_bit_function+0x0/0x40 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09ff555>] __rpc_execute+0x105/0x220 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09ff696>] rpc_execute+0x26/0x30 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09f7b8a>] rpc_run_task+0x3a/0x90 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa09f7ce2>] rpc_call_sync+0x42/0x70 [sunrpc] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81055080>] ? finish_task_switch+0x50/0xd0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0baa0ed>] nfs4_proc_renew+0x4d/0xa0 [nfs] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb61fc>] nfs4_check_lease+0x8c/0xc0 [nfs] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6fa0>] ? nfs4_run_state_manager+0x0/0x40 [nfs] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6e98>] nfs4_state_manager+0xf8/0x200 [nfs] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff810672ed>] ? allow_signal+0x9d/0xb0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffffa0bb6fc3>] nfs4_run_state_manager+0x23/0x40 [nfs] > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81083286>] kthread+0x96/0xa0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff8101422a>] child_rip+0xa/0x20 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff810831f0>] ? kthread+0x0/0xa0 > >> Feb 12 16:11:38 nexus6 kernel: [10629.733513] [<ffffffff81014220>] ? child_rip+0x0/0x20 > >> > >> Here, the mount appears to be attempting to renew the state. > >> > >> <wild ass speculation> > >> Another thread (not shown in the sysrq-t) is attempting to do writeback > >> (maybe the bdev flush thread?) and that's in turn blocked by the state > >> recovery code? > >> </wild ass speculation> > >> > >> Looking back over the capture that you sent originally, I see that the > >> client is attempting a WRITE, getting a NFS4ERR_BAD_STATEID back from > >> the server, issuing a RENEW which succeeds and then reattempting the > >> WRITE. > >> > >> Trond, shouldn't it be trying to recover the state before reissuing the > >> write? > >> > > > > Yes. Both nfs4_read_done() and nfs4_write_done() will call > > nfs4_async_handle_error(), which again should call > > nfs4_state_mark_reclaim_nograce() on the stateid. The state manager > > should then end up recovering that stateid before the write is > > reattempted. > > > > We did previously have an issue if the server were to return > > NFS4ERR_STALE_STATEID, followed by NFS4ERR_OK to our RENEW probe > > (==seriously buggy server), but 2.6.33-rc7 has a fix for that. > > The offending app seems to be the new "indicator-applet" on the Ubuntu > GNOME desktop, so maybe that's why others haven't seen this bug yet? > Here's the trace from dmesg: > > [482400.730245] INFO: task indicator-apple:28782 blocked for more than 120 seconds. > [482400.730247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. > [482400.730249] indicator-app D 0000000000000000 0 28782 1 0x00000080 > [482400.730253] ffff880010579ac8 0000000000000082 0000000000015bc0 0000000000015bc0 > [482400.730257] ffff880109bb1ab0 ffff880010579fd8 0000000000015bc0 ffff880109bb16f0 > [482400.730261] 0000000000015bc0 ffff880010579fd8 0000000000015bc0 ffff880109bb1ab0 > [482400.730265] Call Trace: > [482400.730275] [<ffffffffa0b6b2b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs] > [482400.730279] [<ffffffff8153eb57>] io_schedule+0x47/0x70 > [482400.730288] [<ffffffffa0b6b2be>] nfs_wait_bit_uninterruptible+0xe/0x20 [nfs] > [482400.730292] [<ffffffff8153f3af>] __wait_on_bit+0x5f/0x90 > [482400.730302] [<ffffffffa0b6b2b0>] ? nfs_wait_bit_uninterruptible+0x0/0x20 [nfs] > [482400.730305] [<ffffffff8153f458>] out_of_line_wait_on_bit+0x78/0x90 > [482400.730309] [<ffffffff81085360>] ? wake_bit_function+0x0/0x40 > [482400.730318] [<ffffffffa0b6b29f>] nfs_wait_on_request+0x2f/0x40 [nfs] > [482400.730329] [<ffffffffa0b6f6af>] nfs_wait_on_requests_locked+0x7f/0xd0 [nfs] > [482400.730340] [<ffffffffa0b70aee>] nfs_sync_mapping_wait+0x9e/0x1a0 [nfs] > [482400.730350] [<ffffffffa0b70ed9>] nfs_write_mapping+0x79/0xb0 [nfs] > [482400.730361] [<ffffffffa0b70f47>] nfs_wb_all+0x17/0x20 [nfs] > [482400.730369] [<ffffffffa0b5feba>] nfs_do_fsync+0x2a/0x60 [nfs] > [482400.730378] [<ffffffffa0b608b6>] nfs_file_write+0x106/0x1e0 [nfs] > [482400.730381] [<ffffffff8114270a>] do_sync_write+0xfa/0x140 > [482400.730385] [<ffffffff81085320>] ? autoremove_wake_function+0x0/0x40 > [482400.730389] [<ffffffff81250b96>] ? security_file_permission+0x16/0x20 > [482400.730392] [<ffffffff81142a08>] vfs_write+0xb8/0x1a0 > [482400.730396] [<ffffffff810c03e2>] ? audit_syscall_entry+0x242/0x270 > [482400.730399] [<ffffffff811432a1>] sys_write+0x51/0x80 > [482400.730403] [<ffffffff810131b2>] system_call_fastpath+0x16/0x1b > > I haven't tried the 2.6.34-series yet.. > ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: session hangs with 2.6.33rc7 & nfs-utils 1.2.2rc9 2010-05-06 16:57 ` Trond Myklebust @ 2010-05-14 6:43 ` Timo Aaltonen [not found] ` <alpine.DEB.2.00.1005140942440.13223-9o+TK994UVukEuhtYYxXtw@public.gmane.org> 0 siblings, 1 reply; 4+ messages in thread From: Timo Aaltonen @ 2010-05-14 6:43 UTC (permalink / raw) To: Trond Myklebust; +Cc: linux-nfs, Jeff Layton On Thu, 6 May 2010, Trond Myklebust wrote: > On Thu, 2010-05-06 at 18:40 +0300, Timo Aaltonen wrote: >> Reviving the old thread, since it's still happening. Maybe I should file a >> proper bug about this? > > Please do. Can you see if you can get a trace of the recovery thread? > Also, please check your dmesg log for any 'unhandled error' messages. If > there is nothing there, then we may have to get a 'wireshark' trace > too... Alright, here we go: https://bugzilla.kernel.org/show_bug.cgi?id=15973 -- Timo Aaltonen Systems Specialist IT Services, Aalto University ^ permalink raw reply [flat|nested] 4+ messages in thread
[parent not found: <alpine.DEB.2.00.1005140942440.13223-9o+TK994UVukEuhtYYxXtw@public.gmane.org>]
* Re: session hangs with 2.6.33rc7 & nfs-utils 1.2.2rc9 [not found] ` <alpine.DEB.2.00.1005140942440.13223-9o+TK994UVukEuhtYYxXtw@public.gmane.org> @ 2010-06-04 13:36 ` Timo Aaltonen 0 siblings, 0 replies; 4+ messages in thread From: Timo Aaltonen @ 2010-06-04 13:36 UTC (permalink / raw) To: linux-nfs; +Cc: Trond Myklebust, Jeff Layton On Fri, 14 May 2010, Timo Aaltonen wrote: > On Thu, 6 May 2010, Trond Myklebust wrote: > >> On Thu, 2010-05-06 at 18:40 +0300, Timo Aaltonen wrote: >>> Reviving the old thread, since it's still happening. Maybe I should file a >>> proper bug about this? >> >> Please do. Can you see if you can get a trace of the recovery thread? >> Also, please check your dmesg log for any 'unhandled error' messages. If >> there is nothing there, then we may have to get a 'wireshark' trace >> too... > > Alright, here we go: > > https://bugzilla.kernel.org/show_bug.cgi?id=15973 Still the same with 2.6.34. I'm trying to reproduce it on Redhat/Fedora, but RHEL6 beta installation fails with a kernel panic, and F13 claims that the root ticket cache is "expired or corrupt" (created with 'kinit -k HOST$', looks just fine with klist). Logins work fine, just can't mount the share :) I tried to use 'nsupdate -g' and it complained the same, so I'm not sure what to blame. I'm amazed that no-one else has complained so far, that's why I'd like to try if this happens on another recent distro as well.. -- Timo Aaltonen Systems Specialist Aalto University IT ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2010-06-04 13:44 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <alpine.DEB.2.00.1002111604420.18032@kosh.hut.fi>
[not found] ` <1265897747.478.1.camel@localhost>
[not found] ` <alpine.DEB.2.00.1002111616470.18032@kosh.hut.fi>
[not found] ` <1265898673.478.3.camel@localhost>
[not found] ` <20100211102322.1581a385@barsoom.rdu.redhat.com>
[not found] ` <alpine.DEB.2.00.1002112017550.18032@kosh.hut.fi>
[not found] ` <alpine.DEB.2.00.1002112114190.18032@kosh.hut.fi>
[not found] ` <20100211152822.622dcc70@barsoom.rdu.redhat.com>
[not found] ` <alpine.DEB.2.00.1002121410090.18032@kosh.hut.fi>
[not found] ` <alpine.DEB.2.00.1002121615290.18032@kosh.hut.fi>
[not found] ` <20100212143249.GA17928@fieldses.org>
[not found] ` <alpine.DEB.2.00.1002121705390.18032@kosh.hut.fi>
[not found] ` <20100212111343.101fd0ce@tlielax.poochiereds.net>
[not found] ` <1265998794.2832.23.camel@localhost>
2010-05-06 15:40 ` session hangs with 2.6.33rc7 & nfs-utils 1.2.2rc9 Timo Aaltonen
[not found] ` <alpine.DEB.2.00.1005061730460.3282-9o+TK994UVukEuhtYYxXtw@public.gmane.org>
2010-05-06 16:57 ` Trond Myklebust
2010-05-14 6:43 ` Timo Aaltonen
[not found] ` <alpine.DEB.2.00.1005140942440.13223-9o+TK994UVukEuhtYYxXtw@public.gmane.org>
2010-06-04 13:36 ` Timo Aaltonen
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).