From owner-freebsd-fs@FreeBSD.ORG Thu May 2 01:19:31 2013 Return-Path: Delivered-To: freebsd-fs@freebsd.org Received: from mx1.freebsd.org (mx1.FreeBSD.org [8.8.178.115]) by hub.freebsd.org (Postfix) with ESMTP id 0DABF7F9 for ; Thu, 2 May 2013 01:19:31 +0000 (UTC) (envelope-from rmacklem@uoguelph.ca) Received: from esa-annu.net.uoguelph.ca (esa-annu.mail.uoguelph.ca [131.104.91.36]) by mx1.freebsd.org (Postfix) with ESMTP id C80EE1D91 for ; Thu, 2 May 2013 01:19:30 +0000 (UTC) X-IronPort-Anti-Spam-Filtered: true X-IronPort-Anti-Spam-Result: AqAEAHG+gVGDaFvO/2dsb2JhbABSgz6DN7tqgRd0gh8BAQUjVhkCGAICDRkCWQYTiAyTXZsUkEWBI4w9EH4BMweCP4ETA5cpkTGDKSCBNjU X-IronPort-AV: E=Sophos;i="4.87,592,1363147200"; d="scan'208";a="26357286" Received: from erie.cs.uoguelph.ca (HELO zcs3.mail.uoguelph.ca) ([131.104.91.206]) by esa-annu.net.uoguelph.ca with ESMTP; 01 May 2013 21:19:28 -0400 Received: from zcs3.mail.uoguelph.ca (localhost.localdomain [127.0.0.1]) by zcs3.mail.uoguelph.ca (Postfix) with ESMTP id 05B4FB3F13; Wed, 1 May 2013 21:19:29 -0400 (EDT) Date: Wed, 1 May 2013 21:19:28 -0400 (EDT) From: Rick Macklem To: "Marc G. Fournier" Message-ID: <1032981589.58481.1367457568966.JavaMail.root@erie.cs.uoguelph.ca> In-Reply-To: <531F8BBE-1476-4591-BABD-EA6B230ADB44@hub.org> Subject: Re: Initial NFS Test: Linux vs FreeBSD (769% slower) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Originating-IP: [172.17.91.202] X-Mailer: Zimbra 6.0.10_GA_2692 (ZimbraWebClient - FF3.0 (Linux)/6.0.10_GA_2692) Cc: freebsd-fs@freebsd.org X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 02 May 2013 01:19:31 -0000 Marc G. Fournier wrote: > On 2013-04-30, at 05:29 , Rick Macklem < rmacklem@uoguelph.ca > wrote: >=20 >=20 > Marc G. Fournier wrote: >=20 >=20 > If you want, you can email me startup.pcap as an attachment and I'll > take > a look, but wireshark is pretty good at spotting TCP retransmits, etc. >=20 >=20 > 'k, at 4.x Gig in size, doubt your mail server will handle me sending > this to you :) Even compressed, it was going over 400M =E2=80=A6 I can if= you > want it though =E2=80=A6 >=20 >=20 > Baring that, if you want to give me pointers as to what I should be > looking for? I have Wireshark installed / and the startup.pcap data > loaded =E2=80=A6 the only thing that is jumping out at me is a bunch of l= ines > where 'Length' is 32982 while most are 218 =E2=80=A6 highlighted in 'blac= k > background, red font' =E2=80=A6 for example: >=20 > The big one is a write RPC and it will be a little more than 32768, if > you've set wsize=3D32768. >=20 > This can't be a capture for the "nfsstat" numbers you emailed the last > time. > (For one thing, that one didn't have any write RPCs counted.) Try and > get > a capture for the case where there are few NFS RPCs. (Did you capture > for > the first time doing the startup after doing a mount vs do an > "nfsstat" > for a subsequent startup?) Or, is this client doing something else on > the > network while the startup is happening? >=20 > I may take a look at it, to see if I can spot anything weird, but a > capture > when it only does 88 RPCs is going to be much easier to look at. >=20 >=20 >=20 > 'k, here is what I just ran now =E2=80=A6 igb1 is the private IP network = where > the NFS mount is running from =E2=80=A6 host 192.168.1.5 is the host IP o= f the > server that I'm using for testing =E2=80=A6 and the results again have WR= ITE > calls in it =E2=80=A6 >=20 >=20 > note that when I run the tcpdump command, I'm in /tmp on the local > file system, so I'm not writing that log to the NFS server =E2=80=A6 and = there > is nothing else running on the NFS mount, since all tha tis on it is > /usr/local/jboss=E2=80=A6 =E2=80=A6 the rest of /usr/local is on the loca= l drives also > =E2=80=A6 the WRITEs are to /usr/local/jboss/standalone/logs =E2=80=A6 so= not sure why > RPC Counts for Writes is showing 0 change =E2=80=A6 >=20 >=20 > I'm building a new bz2 file right now, but it looks pretty similar to > the one I already sent you a URL for ... >=20 >=20 >=20 > root@server04:/tmp # nfsstat -c; tcpdump -i igb1 -s 0 -w startup.pcap > host 192.168.1.5 > Client Info: > Rpc Counts: > Getattr Setattr Lookup Readlink Read Write Create Remove > 2746536 821481 974263 18 2230948 2098303 160726 4954 > Rename Link Symlink Mkdir Rmdir Readdir RdirPlus Access > 1862 0 0 14724 950 16272 0 330261 > Mknod Fsstat Fsinfo PathConf Commit > 12 30926 6 0 0 > Rpc Info: > TimedOut Invalid X Replies Retries Requests > 0 0 0 0 9432366 > Cache Info: > Attr Hits Misses Lkup Hits Misses BioR Hits Misses BioW Hits Misses > 26331524 2746535 20540473 974231 2380075 2225802 2618800 2097243 > BioRLHits Misses BioD Hits Misses DirE Hits Misses Accs Hits Misses > 1262 18 46863 15678 29941 0 22516391 330264 > tcpdump: listening on igb1, link-type EN10MB (Ethernet), capture size > 65535 bytes > ^C5454815 packets captured > 5458144 packets received by filter > 0 packets dropped by kernel >=20 >=20 >=20 >=20 > root@server04:/tmp # nfsstat -c > Client Info: > Rpc Counts: > Getattr Setattr Lookup Readlink Read Write Create Remove > 2746603 821481 974276 18 2230953 2098303 160726 4954 > Rename Link Symlink Mkdir Rmdir Readdir RdirPlus Access > 1862 0 0 14724 950 16272 0 330275 > Mknod Fsstat Fsinfo PathConf Commit > 12 30926 6 0 0 > Rpc Info: > TimedOut Invalid X Replies Retries Requests > 0 0 0 0 9432465 > Cache Info: > Attr Hits Misses Lkup Hits Misses BioR Hits Misses BioW Hits Misses > 26332545 2746602 20540712 974244 2380801 2225807 2618800 2097243 > BioRLHits Misses BioD Hits Misses DirE Hits Misses Accs Hits Misses > 1262 18 46863 15678 29941 0 22516700 330278 >=20 >=20 >=20 >=20 >=20 >=20 >=20 >=20 >=20 >=20 >=20 > rick >=20 >=20 >=20 >=20 >=20 >=20 >=20 > i am doing a bzip2 compressed file right now, and will make it > available via HTTP, if you are interested =E2=80=A6 >=20 >=20 >=20 >=20 >=20 >=20 > The only other thing I can suggest is taking the "soft,intr" options > off > your mount and see if that has any effect. Maybe some syscall is > returning > EINTR and confusing jboss? >=20 >=20 > Tried removing soft,intr =E2=80=A6 no change, still around 240s =E2=80=A6 Well, I looked at the packet capture and, for some reason, it repeatedly does a write of 1 byte to a file, followed by a read of that file, over and over and ... again. I have no idea why the app. does that. I also don't know why the "nfsstat -c" is bogus. Are you using "-t oldnfs" for the mount for these runs by any chance? If so, you need to use "nfsstat -o -c". rick ps: To be honest, I doubt that anything can be done to speed this up, except to move it to a local disk.