NFS hangs with 2.6.25/2.6.26 despite server being reachable

NFS hangs with 2.6.25/2.6.26 despite server being reachable

[Michel Lespinasse]

I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
NFS clients, while 2.6.24 seems to work fine.

Here are some details about my configuration:

* The NFS server is a linux host (x86-64) running 2.6.22.19;

* I have two diskless clients using different hardware, one is an old
  AMD K7 with intel pro/100 adapter, the other is x86-64 with on-board
  intel e1000e networking.

* The clients boot from a small initrd and mount their rootfs using
  NFS3 over TCP. The initial mounting is done with "nfsmount -o ro,nolock"
  from the klibc-utils package.

* /etc/fstab in the clients describe the nfs root as having the nolock,noatime
  options. The boot scripts (unmodified from my debian etch distro)
  remount the root using these. In the end, /proc/mounts shows the rootfs as
  using the following options:
  When running 2.6.24 on the client:
    rw,noatime,vers=3,rsize=131072,wsize=131072,hard,nointr,
    nolock,proto=tcp,timeo=7,retrans=3,sec=sys
  When running 2.6.26 on the client:
    rw,noatime,vers=3,rsize=131072,wsize=131072,namlen=255,hard,nointr,
    nolock,proto=tcp,timeo=7,retrans=3,sec=sys,mountproto=udp

* I often run suspend-to-ram on the clients, if I know they'll be unused
  for a few hours.

The above setup works just fine when running 2.6.24 on the clients.

When running 2.6.25 on the clients, the rootfs often hangs after a
suspend/resume cycle. This happens most often if the clients had been
suspended for a while (say overnight, rather than just during dinner).
By 'hangs' I mean the the clients show all symptoms that would be expected
if the server was gone, i.e. processes can't access the filesystem,
load goes to high values, machine becomes basically unusable. However,
the clients are still pingable from the NFS server host, so I believe
the network itself is fine. After 5-10 minutes of this, everything comes
back to normal without any intervention on my part.

When running 2.6.26 on the clients, the same behavior is observed except that
it never goes back to normal. Actually, I could not find any way to fix the
clients without rebooting them.

I'm not sure what's going on. My best guess would be that something times
out (possibly the TCP connection itself ?) and that the NFS client in 2.6.25
and above takes a very long time before giving up and establishing a new
connection with the server ??? I'm not sure if that makes any sense, and I
was not able to collect hard evidence of that so far...

Any ideas about what might be going wrong and/or what additional information
I should try to collect about the hangs ?

Thanks,

-- 
Michel "Walken" Lespinasse
A program is never fully debugged until the last user dies.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[J. Bruce Fields]

On Tue, Jul 15, 2008 at 10:40:53PM -0700, Michel Lespinasse wrote:
> I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
> NFS clients, while 2.6.24 seems to work fine.
> 
> Here are some details about my configuration:
> 
> * The NFS server is a linux host (x86-64) running 2.6.22.19;
> 
> * I have two diskless clients using different hardware, one is an old
>   AMD K7 with intel pro/100 adapter, the other is x86-64 with on-board
>   intel e1000e networking.
> 
> * The clients boot from a small initrd and mount their rootfs using
>   NFS3 over TCP. The initial mounting is done with "nfsmount -o ro,nolock"
>   from the klibc-utils package.
> 
> * /etc/fstab in the clients describe the nfs root as having the nolock,noatime
>   options. The boot scripts (unmodified from my debian etch distro)
>   remount the root using these. In the end, /proc/mounts shows the rootfs as
>   using the following options:
>   When running 2.6.24 on the client:
>     rw,noatime,vers=3,rsize=131072,wsize=131072,hard,nointr,
>     nolock,proto=tcp,timeo=7,retrans=3,sec=sys
>   When running 2.6.26 on the client:
>     rw,noatime,vers=3,rsize=131072,wsize=131072,namlen=255,hard,nointr,
>     nolock,proto=tcp,timeo=7,retrans=3,sec=sys,mountproto=udp
> 
> * I often run suspend-to-ram on the clients, if I know they'll be unused
>   for a few hours.
> 
> The above setup works just fine when running 2.6.24 on the clients.
> 
> When running 2.6.25 on the clients, the rootfs often hangs after a
> suspend/resume cycle. This happens most often if the clients had been
> suspended for a while (say overnight, rather than just during dinner).
> By 'hangs' I mean the the clients show all symptoms that would be expected
> if the server was gone, i.e. processes can't access the filesystem,
> load goes to high values, machine becomes basically unusable. However,
> the clients are still pingable from the NFS server host, so I believe
> the network itself is fine. After 5-10 minutes of this, everything comes
> back to normal without any intervention on my part.
> 
> When running 2.6.26 on the clients, the same behavior is observed except that
> it never goes back to normal. Actually, I could not find any way to fix the
> clients without rebooting them.
> 
> I'm not sure what's going on. My best guess would be that something times
> out (possibly the TCP connection itself ?) and that the NFS client in 2.6.25
> and above takes a very long time before giving up and establishing a new
> connection with the server ??? I'm not sure if that makes any sense, and I
> was not able to collect hard evidence of that so far...
> 
> Any ideas about what might be going wrong and/or what additional information
> I should try to collect about the hangs ?

A sysrq-T trace showing where the clients were hung might help.  (So,
"echo T >/proc/sysrq-trigger", then look at the logs.)

If it were possible to get it down to a simple test case, then we'd
probably learn something from a git-bisect to figure out exactly when
the problem was first introduced.

--b.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[Michel Lespinasse]

On Wed, Jul 16, 2008 at 03:15:53PM -0400, J. Bruce Fields wrote:
> On Tue, Jul 15, 2008 at 10:40:53PM -0700, Michel Lespinasse wrote:
> > I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
> > NFS clients, while 2.6.24 seems to work fine.
> > [...]
> > Any ideas about what might be going wrong and/or what additional
> > information I should try to collect about the hangs ?
>
> A sysrq-T trace showing where the clients were hung might help.  (So,
> "echo T >/proc/sysrq-trigger", then look at the logs.)

Thanks for the reply. I'm now running 2.6.25.11 with sysrq enabled.
Have not captured the failure yet, but then again it's been only one night.
I prefer to go with 2.6.25 instead of 2.6.26 because 2.6.25 generally
recovers from the failure after a few minutes - so there is a higher chance
that I'll actually get something useful logged.

> If it were possible to get it down to a simple test case, then we'd
> probably learn something from a git-bisect to figure out exactly when
> the problem was first introduced.

I wish I had a better way to reproduce this... as it is it happens only
every 2 or 3 days (with 2.6.25.4, but I suppose 2.6.25.11 will be the same)

I'll let you know when I capture a good trace.

-- 
Michel "Walken" Lespinasse
A program is never fully debugged until the last user dies.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[J. Bruce Fields]

On Thu, Jul 17, 2008 at 11:04:05PM -0700, Michel Lespinasse wrote:
> On Wed, Jul 16, 2008 at 03:15:53PM -0400, J. Bruce Fields wrote:
> > On Tue, Jul 15, 2008 at 10:40:53PM -0700, Michel Lespinasse wrote:
> > > I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
> > > NFS clients, while 2.6.24 seems to work fine.
> > > [...]
> > > Any ideas about what might be going wrong and/or what additional
> > > information I should try to collect about the hangs ?
> >
> > A sysrq-T trace showing where the clients were hung might help.  (So,
> > "echo T >/proc/sysrq-trigger", then look at the logs.)
> 
> Thanks for the reply. I'm now running 2.6.25.11 with sysrq enabled.
> Have not captured the failure yet, but then again it's been only one night.
> I prefer to go with 2.6.25 instead of 2.6.26 because 2.6.25 generally
> recovers from the failure after a few minutes - so there is a higher chance
> that I'll actually get something useful logged.
> 
> > If it were possible to get it down to a simple test case, then we'd
> > probably learn something from a git-bisect to figure out exactly when
> > the problem was first introduced.
> 
> I wish I had a better way to reproduce this... as it is it happens only
> every 2 or 3 days (with 2.6.25.4, but I suppose 2.6.25.11 will be the same)
> 
> I'll let you know when I capture a good trace.

OK, thanks.

--b.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[Michel Lespinasse]

On Thu, Jul 17, 2008 at 11:04:05PM -0700, Michel Lespinasse wrote:
> On Wed, Jul 16, 2008 at 03:15:53PM -0400, J. Bruce Fields wrote:
> > On Tue, Jul 15, 2008 at 10:40:53PM -0700, Michel Lespinasse wrote:
> > > I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
> > > NFS clients, while 2.6.24 seems to work fine.
> > > [...]
> > > Any ideas about what might be going wrong and/or what additional
> > > information I should try to collect about the hangs ?
> >
> > A sysrq-T trace showing where the clients were hung might help.  (So,
> > "echo T >/proc/sysrq-trigger", then look at the logs.)
> 
> Thanks for the reply. I'm now running 2.6.25.11 with sysrq enabled.
> Have not captured the failure yet, but then again it's been only one night.
> I prefer to go with 2.6.25 instead of 2.6.26 because 2.6.25 generally
> recovers from the failure after a few minutes - so there is a higher chance
> that I'll actually get something useful logged.

It took me a while, as for some reason I could not get things to fail
this week (It's probably that I don't know all the factors that trigger
the NFS hangs, yet). Then today I got two NFS hangs in a row, running
kernel version 2.6.25.11 on my K7 based client.

In both cases I captured information using alt-sysreq-t, the system
hung there for a few minutes, I double checked that the machine was
pingable from the server, and I got the dumps out of kern.log after
the machine recovered. The logs are incomplete, given that syslog
could not run well with the rootfs hung. I'm not sure if a larger
dmesg buffer would help ? Anyway, please get the logs from

http://lespinasse.org/kern.log
http://lespinasse.org/kern.log.2nd

In both cases I see a lot of nfs_wait_schedule, wait_on_bit_lock,
nfs_revalidate_inode, nfs_check_verifier. Not sure if that's expected,
but that's what I get, and the machine is pingable from the server side.

Hope this helps. Let me know if you want me to try something else.

-- 
Michel "Walken" Lespinasse
A program is never fully debugged until the last user dies.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[J. Bruce Fields]

On Sun, Jul 20, 2008 at 07:14:08PM -0700, Michel Lespinasse wrote:
> On Thu, Jul 17, 2008 at 11:04:05PM -0700, Michel Lespinasse wrote:
> > On Wed, Jul 16, 2008 at 03:15:53PM -0400, J. Bruce Fields wrote:
> > > On Tue, Jul 15, 2008 at 10:40:53PM -0700, Michel Lespinasse wrote:
> > > > I'm getting frequent NFS hangs when running 2.6.25 or 2.6.26 on my
> > > > NFS clients, while 2.6.24 seems to work fine.
> > > > [...]
> > > > Any ideas about what might be going wrong and/or what additional
> > > > information I should try to collect about the hangs ?
> > >
> > > A sysrq-T trace showing where the clients were hung might help.  (So,
> > > "echo T >/proc/sysrq-trigger", then look at the logs.)
> > 
> > Thanks for the reply. I'm now running 2.6.25.11 with sysrq enabled.
> > Have not captured the failure yet, but then again it's been only one night.
> > I prefer to go with 2.6.25 instead of 2.6.26 because 2.6.25 generally
> > recovers from the failure after a few minutes - so there is a higher chance
> > that I'll actually get something useful logged.
> 
> It took me a while, as for some reason I could not get things to fail
> this week (It's probably that I don't know all the factors that trigger
> the NFS hangs, yet). Then today I got two NFS hangs in a row, running
> kernel version 2.6.25.11 on my K7 based client.
> 
> In both cases I captured information using alt-sysreq-t, the system
> hung there for a few minutes, I double checked that the machine was
> pingable from the server, and I got the dumps out of kern.log after
> the machine recovered. The logs are incomplete, given that syslog
> could not run well with the rootfs hung. I'm not sure if a larger
> dmesg buffer would help ? Anyway, please get the logs from
> 
> http://lespinasse.org/kern.log
> http://lespinasse.org/kern.log.2nd

Oh, sorry, I think I overlooked the note in your original message that
this happened after suspend-to-ram.  That's interesting!  You really
need someone with more experience debugging the rpc client.... It might
also be worth turning on rpc debugging during the hang just to get the
dump of rpc task states.  (So

	echo 0 >/proc/sys/sunrpc/rpc_debug

and capture the first table it dumps to the log.  Or Trond or Chuck
might have some better idea.)

--b.

> 
> In both cases I see a lot of nfs_wait_schedule, wait_on_bit_lock,
> nfs_revalidate_inode, nfs_check_verifier. Not sure if that's expected,
> but that's what I get, and the machine is pingable from the server side.
> 
> Hope this helps. Let me know if you want me to try something else.
> 
> -- 
> Michel "Walken" Lespinasse
> A program is never fully debugged until the last user dies.

Re: NFS hangs with 2.6.25/2.6.26 despite server being reachable

[Michel Lespinasse]

On Wed, Jul 23, 2008 at 05:52:10PM -0400, J. Bruce Fields wrote:
> Oh, sorry, I think I overlooked the note in your original message that
> this happened after suspend-to-ram.  That's interesting!  You really
> need someone with more experience debugging the rpc client.... It might
> also be worth turning on rpc debugging during the hang just to get the
> dump of rpc task states.  (So
> 
> 	echo 0 >/proc/sys/sunrpc/rpc_debug
> 
> and capture the first table it dumps to the log.  Or Trond or Chuck
> might have some better idea.)

Since it does not look like we'll solve this overnight, I opened
bug 11154 to track this. Please feel free to suggest what to try there...

Thanks,

-- 
Michel "Walken" Lespinasse
A program is never fully debugged until the last user dies.