lkml.org 
[lkml]   [1999]   [May]   [27]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: Possible NFS client 2.2.9 kernel bug
Trond,

I took your advice and did some more debugging, the summary is that the
problem goes away with rsize and wsize set to 1024, but either 4096 or
8192 gives the infinite loop on the troublesome directory. Mounting the
identical export to a 2.0.36/lib5 machine with any r/wsize works fine.
Please take a look at the output below and tell me where to look next
(assuming you think this is worth tracking down). Seems to only happen on
a directory with particular entries, thus it is hard to generate on
demand, other setups here at the U have also seen the same problem. But I
have a repeatable setup on machines I can play with at home.

Here is the client setup (should have given this originally):

y2% sh ver_linux
-- Versions installed: (if some fields are empty or looks
-- unusual then possibly you have very old versions)
Linux y2.aem.umn.edu 2.2.9 #3 Mon May 17 18:44:42 CDT 1999 i686 unknown
Kernel modules 2.1.121
Gnu C 2.7.2.3
Binutils 2.9.1.0.15
Linux C Library 2.1.1
Dynamic linker ldd (GNU libc) 2.1.1
Linux C++ Library 2.8.0
Procps 1.2.9
Mount 2.8a
Net-tools 1.50
Kbd 0.96
Sh-utils 1.16
Modules Loaded nfs lockd sunrpc

server is nfs-server-2.2beta37, kernel 2.2.6, glibc.

With default mount (4096 rsize, wsize): when I do a readdir() loop on the
troublesome directory, a tcpdump gives (soling is the server, y2 the client)

Unknown/1 "basic" (ttl 64, id 33631)
19:56:34.782400 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1181811596: reply ok 128 lookup fh Unknown/1 DIR 40555 ids 0/0 sz 12288 nlink 1 rdev 0 fsid 1 nodeid 720037f1 a/m/ctime 927494691.000000 856320951.000000 856320849.000000 (ttl 64, id 423)
19:56:34.784981 y2.aem.umn.edu.1198588812 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 4096 bytes @ 0 (ttl 64, id 33632)
19:56:34.787506 soling.aem.umn.edu > y2.aem.umn.edu: (frag 424:1032@1480) (ttl 64)
19:56:34.787626 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1198588812: reply ok 1472 readdir offset 1 size 1912616955 eof (frag 424:1480@0+) (ttl 64)

so tcpdump sees the eof as I understand this.

in nfs2xdr.c have:

status = !p[0] && p[1] ? (1 << 15) : 0; /* eof flag */
*entry++ = fileid;
*entry++ = cookie;
*entry++ = ((string - start) << 16) | status | (len & 0x7FFF);

if(status)
{
dfprintk(VFS, "NFS: 2 p[0] = %u p[1] = %u \n",p[0],p[1]);
dfprintk(VFS, "NFS: got EOF bit \n");
}
else
{
dfprintk(VFS, "NFS: 2 p[0] = %u p[1] = %u \n",p[0],p[1]);
}
}

and this gives:

May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 473432178
May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 540541042
May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 1060634738
May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 1178075250
May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 1677716 p[1] = 4046913650
May 25 19:56:34 y2 kernel: NFS: 2 p[0] = 0 p[1] = 0
May 25 19:56:34 y2 kernel: TWS: EOF bit NOT set

the last line is from my check in dir.c as per my original (wrong) patch
(which is disabled, I just left the dfprintk's in) and then the code goes
into the infinite loop of looking in the cache, not finding the eof...

run the same thing with 1024 rsize and wsize:

20:01:55.365726 y2.aem.umn.edu.1383138188 > soling.aem.umn.edu.nfs: 124 lookup fh Unknown/1 "basic" (ttl 64, id 33882)
20:01:55.366248 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1383138188: reply ok 128 lookup fh Unknown/1 DIR 40555 ids 0/0 sz 12288 nlink 1 rdev 0 fsid 1 nodeid 720037f1 a/m/ctime 927494691.000000 856320951.000000 856320849.000000 (ttl 64, id 438)
20:01:55.368607 y2.aem.umn.edu.1399915404 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 0 (ttl 64, id 33883)
20:01:55.370208 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1399915404: reply ok 516 readdir offset 1 size 1912616955 eof (ttl 64, id 439)
20:01:55.417453 y2.aem.umn.edu.1416692620 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 524305 (ttl 64, id 33884)
20:01:55.418749 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1416692620: reply ok 528 readdir offset 1 size 1912616962 eof (ttl 64, id 440)
20:01:55.421965 y2.aem.umn.edu.1433469836 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 524324 (ttl 64, id 33885)
20:01:55.423245 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1433469836: reply ok 516 readdir offset 1 size 1912616954 eof (ttl 64, id 441)
20:01:55.425283 y2.aem.umn.edu.1450247052 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 1048593 (ttl 64, id 33886)
20:01:55.426452 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1450247052: reply ok 520 readdir offset 1 size 1912616997 eof (ttl 64, id 442)
20:01:55.428622 y2.aem.umn.edu.1467024268 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 1572878 (ttl 64, id 33887)
20:01:55.429599 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1467024268: reply ok 520 readdir offset 1 size 1912616970 eof (ttl 64, id 443)
20:01:55.432389 y2.aem.umn.edu.1483801484 > soling.aem.umn.edu.nfs: 120 readdir fh Unknown/1 1024 bytes @ 1572896 (ttl 64, id 33888)
20:01:55.433110 soling.aem.umn.edu.nfs > y2.aem.umn.edu.1483801484: reply ok 84 readdir offset 1 size 1912617030 eof (ttl 64, id 444)

directory was pulled down in multiple chunks, each chunk ends with:

May 25 20:01:55 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 540541042
May 25 20:01:55 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 1060634738
May 25 20:01:55 y2 kernel: NFS: 2 p[0] = 0 p[1] = 0
May 25 20:01:55 y2 kernel: TWS: EOF bit NOT set

except for the last chunk:

May 25 20:01:55 y2 kernel: NFS: 2 p[0] = 16777216 p[1] = 4046913650
May 25 20:01:55 y2 kernel: NFS: 2 p[0] = 0 p[1] = 16777216
May 25 20:01:55 y2 kernel: NFS: got EOF bit
May 25 20:01:55 y2 kernel: TWS: EOF bit set

note that mounting with rsize and wsize different from 1024 to a 2.0.36,
lib5 (RH4.2+) box works fine. Mounting with 4096 or 8192 does
not work on the 2.2.9 box (the directory takes only one packet in each
case).

I can export a directory that results in a p[0]=0 p[1]=0 on the last
entry, but in that case nfs_readdir() gets called again, does another
nfs_proc_readdir() which returns a value of zero, which causes an exit to
done and all is well. I don't understand why the p[0]=0 p[1]=0 causes the
additional rpc read in one case (which is needed to find the eof) and not
the other (where the eof appears to have already been sent).

Any thoughts or suggestions on which way to go next?

thanks,

Tom Shield
Aerospace Engineering and Mechanics
University of Minnesota
(612) 626-7793
http://www.aem.umn.edu/people/faculty/shield/





-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/

\
 
 \ /
  Last update: 2005-03-22 13:51    [W:0.198 / U:0.108 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site