Date: Tue, 18 Jun 1996 00:32:11 +0200 (MET DST) From: J Wunsch <j@uriah.heep.sax.de> To: freebsd-hackers@freebsd.org (FreeBSD hackers) Subject: NFS (Was: BSDI 2.0 vs. FreeBSD 2.x) Message-ID: <199606172232.AAA05809@uriah.heep.sax.de> In-Reply-To: <21859.835029814@time.cdrom.com> from "Jordan K. Hubbard" at "Jun 17, 96 09:43:34 am"
next in thread | previous in thread | raw e-mail | index | archive | help
As Jordan K. Hubbard wrote: > I'm definitely with you on targeting NFS as one of our weakest spots, > I'm simply still struggling with the problem of identifying and > somehow enlisting the aid of someone who can actually do something > about it. I wondered about the NFS problems last weekend, and did some initial analyzation. Both of the following logs have been taken from a simple `ls -F' of a directory containing many files. /sys/compile/MYMACHINE/ or /usr/local/bin are good candidates. This is part of the log from a working NFS connection. 14:51:11.804997 ida.interface-business.de.35a05 > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:11.835595 innocence.interface-business.de.nfs > ida.interface-business.de.35a05: reply ok 1472 readdir [|nfs] (frag 21238:1480@0+) 14:51:11.842934 ida.interface-business.de.35a06 > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:11.854460 innocence.interface-business.de.nfs > ida.interface-business.de.35a06: reply ok 1472 readdir [|nfs] (frag 21240:1480@0+) 14:51:12.351984 ida.interface-business.de.35a89 > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:12.359891 innocence.interface-business.de.nfs > ida.interface-business.de.35a89: reply ok 1472 readdir [|nfs] (frag 21372:1480@0+) 14:51:12.818578 ida.interface-business.de.35b08 > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:12.827242 innocence.interface-business.de.nfs > ida.interface-business.de.35b08: reply ok 1472 readdir [|nfs] (frag 21500:1480@0+) 14:51:13.312405 ida.interface-business.de.35b8d > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:13.318342 innocence.interface-business.de.nfs > ida.interface-business.de.35b8d: reply ok 1472 readdir [|nfs] (frag 21633:1480@0+) 14:51:13.819386 ida.interface-business.de.35c0d > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:13.821771 innocence.interface-business.de.nfs > ida.interface-business.de.35c0d: reply ok 188 readdir [|nfs] 14:51:13.823558 ida.interface-business.de.35c0f > innocence.interface-business.de.nfs: 128 readdir [|nfs] 14:51:13.830880 innocence.interface-business.de.nfs > ida.interface-business.de.35c0f: reply ok 36 readdir [|nfs] You notice the tight sequence of readdir's (i took out the `lookup's that were scattered among them for brevity -- the lookup's are most likely caused by the -F flag to ls). The entire listing of a huge directory was done within 2 seconds (where it's even likely that the operation has been additionally deferred by me taking the output of either the `ls' and the `tcpdump' across a slow modem connection). ida.interface-business.de above is a -current kernel as of around the time John has been committing his recent VM changes (but without these changes). The following is an extract of a similar operation for an NFS mount that sucks. 16:26:31.433601 uriah.heep.sax.de.288 > uncle.heep.sax.de.nfs: 120 readdir [|nfs] 16:26:31.445659 uncle.heep.sax.de.nfs > uriah.heep.sax.de.288: reply ok 1472 readdir [|nfs] (frag 701:1480@0+) 16:26:32.450097 uriah.heep.sax.de.288 > uncle.heep.sax.de.nfs: 120 readdir [|nfs] 16:26:32.461639 uncle.heep.sax.de.nfs > uriah.heep.sax.de.288: reply ok 1472 readdir [|nfs] (frag 702:1480@0+) 16:26:34.480097 uriah.heep.sax.de.288 > uncle.heep.sax.de.nfs: 120 readdir [|nfs] 16:26:34.491754 uncle.heep.sax.de.nfs > uriah.heep.sax.de.288: reply ok 1472 readdir [|nfs] (frag 703:1480@0+) 16:26:34.506036 uriah.heep.sax.de.289 > uncle.heep.sax.de.nfs: 120 readdir [|nfs] It's actually a short one, but you get the picture. The readdir replies are not _immediately_ followed by the next readdir request, instead, the next request is apparently scheduled by a timeout procedure, thus issued only 1/2/4/8 etc. seconds later. You get the idea what this means for a large directory... uriah.heep.sax.de is my development machine at home. The above effect was apparent with a kernel as of a couple of months ago as well as with the most recent kernel as of yesterday morning. It happens consistently whenever this machine acts as an NFS client, regardless of the system on the NFS server (i've also tried a public anon FTP server nearby which is an Ultrix machine), and regardless of whether i'm using ethernet or for example mounting across a SLIP line. It's always the same pictures, the subsequent readdir's are only done after 1/2/4/etc. seconds of timing out. I tried to dig into the source, but it's not very apparent from the first glance which code is responsible for sending the next readdir in the scenario above... -- cheers, J"org joerg_wunsch@uriah.heep.sax.de -- http://www.sax.de/~joerg/ -- NIC: JW11-RIPE Never trust an operating system you don't have sources for. ;-)
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?199606172232.AAA05809>