2.5.60 NFS FSX

2.5.60 NFS FSX

[Dave Jones]

2.5.60's NFS seems to have various issues.
(2.5.60 client, 2.4.21pre3 server)

- I ran an fsx and an fsstress in parallel.
  Client rebooted after 2-3 minutes.
- fsx on its own, after quite a while, this happens..

truncating to largest ever: 0x3ffff
skipping zero size read
skipping zero size write
skipping zero size write
skipping zero size write
READ BAD DATA: offset = 0x358ba, size = 0x4867
OFFSET	GOOD	BAD	RANGE
0x36000	0x0000	0x8c1a	0x 1ff3
operation# (mod 256) for the bad data may be 140
LOG DUMP (176283 total operations):
176284(156 mod 256): READ	0x35b07 thru 0x38c67	(0x3161 bytes)	***RRRR***
176285(157 mod 256): READ	0x12552 thru 0x1af77	(0x8a26 bytes)
176286(158 mod 256): WRITE	0x3560f thru 0x3ffff	(0xa9f1 bytes)	***WWWW
176287(159 mod 256): MAPWRITE 0x1aaae thru 0x233bf	(0x8912 bytes)
176288(160 mod 256): MAPREAD	0x3635d thru 0x3661b	(0x2bf bytes)
176289(161 mod 256): MAPREAD	0x374c0 thru 0x3ba42	(0x4583 bytes)	***RRRR***
176290(162 mod 256): WRITE	0x16794 thru 0x192eb	(0x2b58 bytes)
176291(163 mod 256): READ	0x128bf thru 0x1d5b0	(0xacf2 bytes)
176292(164 mod 256): READ	0x330d5 thru 0x35b26	(0x2a52 bytes)
176293(165 mod 256): MAPREAD	0xff6b thru 0x13c4e	(0x3ce4 bytes)
176294(166 mod 256): MAPWRITE 0x1c5e0 thru 0x2a720	(0xe141 bytes)
176295(167 mod 256): MAPWRITE 0x2a8df thru 0x2e628	(0x3d4a bytes)
176296(168 mod 256): MAPWRITE 0x370cc thru 0x3be24	(0x4d59 bytes)	******WWWW
176297(169 mod 256): MAPWRITE 0x21637 thru 0x30999	(0xf363 bytes)
... <much more spew .. 
(full log is at http://www.codemonkey.org.uk/cruft/nfs-fsx-2.5.60.txt )

Finally, I see a lot of these in the client logs..

NFS: server cheating in read reply: count 8192 > recvd 1000
NFS: server cheating in read reply: count 8192 > recvd 1000
NFS: server cheating in read reply: count 8192 > recvd 1000
NFS: server cheating in read reply: count 3888 > recvd 1000
NFS: server cheating in read reply: count 8192 > recvd 1000
NFS: server cheating in read reply: count 8192 > recvd 1000
...

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Trond Myklebust]

>>>>> " " == Dave Jones <davej@codemonkey.org.uk> writes:

     > 2.5.60's NFS seems to have various issues.  (2.5.60 client,
     > 2.4.21pre3 server)

     > - I ran an fsx and an fsstress in parallel.
     >   Client rebooted after 2-3 minutes.

I know. There's memory corruption going on somewhere, but I'm not sure
exactly where.

     > - fsx on its own, after quite a while, this happens..

Also known. It's a bit odd really: the reads fail due to some form of
corruption, but the writes are OK. Means that when you later come to
compare the '.fsxgood' file to the 'bad' file, then things look OK.

I'm a bit confused w.r.t. both these issues. Neither occur on the
2.4.x platform despite the fact that the code is more or less the
same. This is why I suspect an IPv4 socket problem.

Cheers,
  Trond

Re: 2.5.60 NFS FSX

[Dave Jones]

On Thu, Feb 13, 2003 at 04:45:27PM +0100, Trond Myklebust wrote:
 > > 2.5.60's NFS seems to have various issues.  (2.5.60 client,
 > > 2.4.21pre3 server)
 > > - I ran an fsx and an fsstress in parallel.
 > >   Client rebooted after 2-3 minutes.
 > I know. There's memory corruption going on somewhere, but I'm not sure
 > exactly where.

Last thing I spotted on a serial terminal was..

RPC: garbage, exit EIO
 
 > I'm a bit confused w.r.t. both these issues. Neither occur on the
 > 2.4.x platform despite the fact that the code is more or less the
 > same. This is why I suspect an IPv4 socket problem.

ok, thanks for looking at it.

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Trond Myklebust]

>>>>> " " == Dave Jones <davej@codemonkey.org.uk> writes:

     > Last thing I spotted on a serial terminal was..

     > RPC: garbage, exit EIO

Right: that's what you would expect for corruption.

Was this by the way an SMP setup? If so, could you try the following
patch (based on a previous patch by Olaf Kirch) and that I sent to Linus
earlier today. It fixes an issue that could on occasion lead to some
pretty nasty corruption issues.

I don't think SMP can explain all the corruption issues though, as
I've also been seeing wierdness on my laptop.

Cheers,
  Trond

diff -u --recursive --new-file linux-2.5.60-00-fix_pipes/net/sunrpc/xprt.c linux-2.5.60-01-fix_xid/net/sunrpc/xprt.c
--- linux-2.5.60-00-fix_pipes/net/sunrpc/xprt.c	2003-01-12 22:39:48.000000000 +0100
+++ linux-2.5.60-01-fix_xid/net/sunrpc/xprt.c	2003-02-13 14:17:10.000000000 +0100
@@ -1273,25 +1273,41 @@
 }
 
 /*
+ * Allocate a 'unique' XID
+ */
+static u32
+xprt_alloc_xid(void)
+{
+	static spinlock_t xid_lock = SPIN_LOCK_UNLOCKED;
+	static int need_init = 1;
+	static u32 xid;
+	u32 ret;
+
+	spin_lock(&xid_lock);
+	if (unlikely(need_init)) {
+		xid = get_seconds() << 12;
+		need_init = 0;
+	}
+	ret = xid++;
+	spin_unlock(&xid_lock);
+	return ret;
+}
+
+/*
  * Initialize RPC request
  */
 static void
 xprt_request_init(struct rpc_task *task, struct rpc_xprt *xprt)
 {
 	struct rpc_rqst	*req = task->tk_rqstp;
-	static u32	xid = 0;
-
-	if (!xid)
-		xid = get_seconds() << 12;
 
-	dprintk("RPC: %4d reserved req %p xid %08x\n", task->tk_pid, req, xid);
 	req->rq_timeout = xprt->timeout;
 	req->rq_task	= task;
 	req->rq_xprt    = xprt;
-	req->rq_xid     = xid++;
-	if (!xid)
-		xid++;
+	req->rq_xid     = xprt_alloc_xid();
 	INIT_LIST_HEAD(&req->rq_list);
+	dprintk("RPC: %4d reserved req %p xid %08x\n", task->tk_pid,
+			req, req->rq_xid);
 }
 
 /*

Re: 2.5.60 NFS FSX

[Dave Jones]

On Thu, Feb 13, 2003 at 05:04:09PM +0100, Trond Myklebust wrote:

 > Was this by the way an SMP setup?

No, single CPU VIA C3.
 
		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Joel Becker]

On Thu, Feb 13, 2003 at 03:27:42PM +0000, Dave Jones wrote:
> 2.5.60's NFS seems to have various issues.
> (2.5.60 client, 2.4.21pre3 server)

	I get these a lot:

NFS: server cheating in read reply: count 1115 recvd 1000

	The counts are various and not consistent.

Joel

-- 

Life's Little Instruction Book #356

	"Be there when people need you."

Joel Becker
Senior Member of Technical Staff
Oracle Corporation
E-mail: joel.becker@oracle.com
Phone: (650) 506-8127

Re: 2.5.60 NFS FSX

[Trond Myklebust]

>>>>> " " == Joel Becker <Joel.Becker@oracle.com> writes:

     > On Thu, Feb 13, 2003 at 03:27:42PM +0000, Dave Jones wrote:
    >> 2.5.60's NFS seems to have various issues.  (2.5.60 client,
    >> 2.4.21pre3 server)

     > 	I get these a lot:

     > NFS: server cheating in read reply: count 1115 recvd 1000

     > 	The counts are various and not consistent.

Does either you have a tcpdump you could send me of one of the above
events? Use a large snaplen since we want to check the readdir reply
length (which tends to be ~4k). Something like

   tcpdump -s 8192 -w dump.out host blah and port 2049

Cheers,
  Trond

Re: 2.5.60 NFS FSX

[Dave Jones]

On Thu, Feb 13, 2003 at 08:08:21PM +0100, Trond Myklebust wrote:

 > Does either you have a tcpdump you could send me of one of the above
 > events? Use a large snaplen since we want to check the readdir reply
 > length (which tends to be ~4k). Something like
 > 
 >    tcpdump -s 8192 -w dump.out host blah and port 2049

Not easily. I'm trying to get an exact reproduction case
(fsx does it 'sometimes').  So far the best I've been able
to get is a 164MB dump file. As soon as I narrow it down
and get a sensible dump size, I'll let you know.

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Trond Myklebust]

>>>>> " " == Dave Jones <davej@codemonkey.org.uk> writes:

     > A tcpdump capture is at .....

     > There seems to be some garbage at the end of the capture.  I'm
     > not sure why, but it seems tcpdump does that sometimes.

Does it do that on 2.4.x? I've certainly never seen that happen on a
stable kernel.

In fact ethereal reports 

 Message: pcap: File has 1045168887-byte packet, bigger than maximum of 65535

No wonder we see bizarre crashes...

There are several other odd features in this tcpdump. Random UDP
packets from the server to the client with a junk payload (usually
consisting of a load of zeros) appear to be pretty frequent.

Is this against a 2.5.x server? If so, could you try against a 2.4.x
or a non-linux server?

Cheers,
  Trond

Note: I saw similar problems when I tried to convert the NFS client to
use the new zero-copy UDP interface (and so I dropped the idea).

Re: 2.5.60 NFS FSX

[Dave Jones]

On Thu, Feb 13, 2003 at 10:12:58PM +0100, Trond Myklebust wrote:

 > > There seems to be some garbage at the end of the capture.  I'm
 > > not sure why, but it seems tcpdump does that sometimes.
 > Does it do that on 2.4.x? I've certainly never seen that happen on a
 > stable kernel.

I'll try in a few minutes. It doesn't always do it in 2.5, just like
once every dozen or so captures.  NIC is a 3com 3c905C-TX/TX-M [Tornado]
in the client, and an Intel 82801BA/BAM/CA/CAM in the server, both
boxes connected through a cheapo 100MB switch. Nothing special.

 > In fact ethereal reports 
 > 
 >  Message: pcap: File has 1045168887-byte packet, bigger than maximum of 65535
 > No wonder we see bizarre crashes...

That did seem odd yes.  I put it down to a tcpdump bug.
But if you think thats whats triggering it...

 > There are several other odd features in this tcpdump. Random UDP
 > packets from the server to the client with a junk payload (usually
 > consisting of a load of zeros) appear to be pretty frequent.

Wacky. Interested netdev parties can find the ~2MB tcpdump output at
http://www.codemonkey.org.uk/cruft/tcp-trond.bz2
(please don't hammer that server with requests for this unless you
 really do want/need it - the mind boggles at how many hits the nfs
 fsx dumps got in the past -- I'm sure we don't have *that* many
 interested NFS developers 8-).

 > Is this against a 2.5.x server? If so, could you try against a 2.4.x
 > or a non-linux server?

This is a 2.4.21pre3 server.  No non-linux servers to try against
right now..

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Dave Jones]

On Thu, Feb 13, 2003 at 10:12:58PM +0100, Trond Myklebust wrote:

 > > There seems to be some garbage at the end of the capture.  I'm
 > > not sure why, but it seems tcpdump does that sometimes.
 > 
 > Does it do that on 2.4.x? I've certainly never seen that happen on a
 > stable kernel.

More datapoints.

2.4.18 - looks ok.
2.5.59 - looks ok. no nfs warnings, no corrupt tcpdump output.

Looks like this is recent breakage.

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs

Re: 2.5.60 NFS FSX

[Dave Jones]

> More datapoints.
>
> 2.4.18 - looks ok.
> 2.5.59 - looks ok. no nfs warnings, no corrupt tcpdump output.

And of course, 2 minutes after writing that, 2.5.59 fell
on its ass in the same way. *sigh*.

		Dave

-- 
| Dave Jones.        http://www.codemonkey.org.uk
| SuSE Labs