Re: [NFS] NFS rpc and stale handles on 2.6.x servers

Re: [NFS] NFS rpc and stale handles on 2.6.x servers

[Neil Brown]

On Sunday January 25, hanasaki@hanaden.com wrote:
> The below is being reported, on and off, when hitting nfs-kernel-servers
> running on 2.6.0 and 2.6.1  Could someone tell me if this is smoe bug or
> what?  Thanks
> 	RPC request reserved 0 but used 124
> 
> Debian sarge
> nfs-kernel-server
> am-untils
> nfsv3 over tcp
> 

stale file handles is a known bug that is fixed in the but BK and will
be in 2.6.3.

The "RPC request reserved 0 ..." is very odd. It does immediately
indicate a major problem, but it should be fixed, if only I could
figure out what was causing it.

I might put come more info into the message so future bug reports will
tell me more.

Thanks,
NeilBrown

Re: [NFS] NFS rpc and stale handles on 2.6.x servers

[Mike Fedyk]

On Fri, Jan 30, 2004 at 11:46:31AM +1100, Neil Brown wrote:
> On Sunday January 25, hanasaki@hanaden.com wrote:
> > The below is being reported, on and off, when hitting nfs-kernel-servers
> > running on 2.6.0 and 2.6.1  Could someone tell me if this is smoe bug or
> > what?  Thanks
> > 	RPC request reserved 0 but used 124
> > 
> > Debian sarge
> > nfs-kernel-server
> > am-untils
> > nfsv3 over tcp
> > 
> 
> stale file handles is a known bug that is fixed in the but BK and will
> be in 2.6.3.

do you mean 2.6.2?

I've merged the nfsd stale file handles into 2.6.1-bk2 and it is working
fine on a nfs server here...

Re: [NFS] NFS rpc and stale handles on 2.6.x servers

[Neil Brown]

On Thursday January 29, mfedyk@matchmail.com wrote:
> On Fri, Jan 30, 2004 at 11:46:31AM +1100, Neil Brown wrote:
> > On Sunday January 25, hanasaki@hanaden.com wrote:
> > > The below is being reported, on and off, when hitting nfs-kernel-servers
> > > running on 2.6.0 and 2.6.1  Could someone tell me if this is smoe bug or
> > > what?  Thanks
> > > 	RPC request reserved 0 but used 124
> > > 
> > > Debian sarge
> > > nfs-kernel-server
> > > am-untils
> > > nfsv3 over tcp
> > > 
> > 
> > stale file handles is a known bug that is fixed in the but BK and will
> > be in 2.6.3.
> 
> do you mean 2.6.2?

Yeh, 2.6.2 as well.. But definitely 2.6.3 :-)

> 
> I've merged the nfsd stale file handles into 2.6.1-bk2 and it is working
> fine on a nfs server here...

good, thanks.
NeilBrown

Re: [NFS] NFS rpc and stale handles on 2.6.x servers

[hanasaki]

Add this to your exportfs "no_subtree_check"  It seems to be a temp 
workaround.  Searching the web, the only issue with this option seems to 
be a minor performance hit (big issue for large systems).  Any chance of 
getting the patch 2.6.2?  www.kernel.org looks like its still on an RC2 
of this.


Neil Brown wrote:
> On Thursday January 29, mfedyk@matchmail.com wrote:
> 
>>On Fri, Jan 30, 2004 at 11:46:31AM +1100, Neil Brown wrote:
>>
>>>On Sunday January 25, hanasaki@hanaden.com wrote:
>>>
>>>>The below is being reported, on and off, when hitting nfs-kernel-servers
>>>>running on 2.6.0 and 2.6.1  Could someone tell me if this is smoe bug or
>>>>what?  Thanks
>>>>	RPC request reserved 0 but used 124
>>>>
>>>>Debian sarge
>>>>nfs-kernel-server
>>>>am-untils
>>>>nfsv3 over tcp
>>>>
>>>
>>>stale file handles is a known bug that is fixed in the but BK and will
>>>be in 2.6.3.
>>
>>do you mean 2.6.2?
> 
> 
> Yeh, 2.6.2 as well.. But definitely 2.6.3 :-)
> 
> 
>>I've merged the nfsd stale file handles into 2.6.1-bk2 and it is working
>>fine on a nfs server here...
> 
> 
> good, thanks.
> NeilBrown

Re: [NFS] NFS rpc and stale handles on 2.6.x servers

[Roman Kagan]

On Fri, Jan 30, 2004 at 10:16:05AM +0000, Neil Brown wrote:
> The "RPC request reserved 0 ..." is very odd. It does immediately
> indicate a major problem, but it should be fixed, if only I could
> figure out what was causing it.

In case it helps: having enabled svcsock debugging by

  echo $[0x0100] > /proc/sys/sunrpc/rpc_debug

I've noticed that those messages always appear in the same pattern:

svc: server c7a3d200 waiting for data (to = 3600000)
svc: socket c6dbfb00(inet c769f220), write_space busy=0
svc: socket c2a9fac0 TCP data ready (svsk c6dbf980)
svc: socket c2a9fac0 served by daemon c7a3d200
svc: socket c2a9fac0 TCP data ready (svsk c6dbf980)
svc: socket c2a9fac0 busy, not enqueued
svc: server c7a3d200, socket c6dbf980, inuse=1
svc: tcp_recv c6dbf980 data 1 conn 0 close 0
svc: socket c6dbf980 recvfrom(c6dbf9d8, 0) = 4
svc: TCP record, 2584 bytes
svc: socket c6dbf980 recvfrom(c6d06a18, 1512) = 2584
svc: TCP complete record (2584 bytes)
svc: socket c2a9fac0 served by daemon c6efe000
svc: got len=2584
svc: socket c2a9fac0 busy, not enqueued
svc: socket c6dbf980 sendto([c436b000 140... ], 140) = 140 (addr 43e17cc1)
svc: socket c2a9fac0 busy, not enqueued
svc: server c7a3d200 waiting for data (to = 3600000)
svc: server c7a3d200, socket c25007a0, inuse=1
svc: tcp_recv c25007a0 data 0 conn 0 close 1
svc: svc_delete_socket(c25007a0)
svc: server socket destroy delayed
svc: got len=0
RPC request reserved 0 but used 140
svc: releasing dead socket
svc: server c7a3d200 waiting for data (to = 3600000)


Note that "tcp_recv" with this set of parameters (data=0 conn=0 close=1)
is always correlated with "RPC request reserved ...", and also the
"used" request length matches the message length in "sendto" on the
seemingly unrelated socket.

Unfortunately I don't understand the code well enough to make a better
bug report, but feel free to ask me to test your patches if you can't
reproduce the problem in your setup.

  Roman.