Messages in this thread | | | Date | Wed, 26 May 1999 10:31:41 -0500 (CDT) | From | Tom Shield <> | Subject | Re: 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/
| |