uuid/blkid performance problem with large number of mounts - was: Re: stale nfs file handle with exported loopback mounts

DISCUSSION [email protected] 3 participants 3 messages Nov 13, 2007 – Nov 15, 2007

Subsystems (2)

NFS client NFS server

lore

Share & tools

lore

[email protected]

author

2007-11-13 22:44 UTC #0 lore raw

since i posted 2 problems in one mail - and one problem is solved now, for = the second problem i have opened a ticket at =

http://sourceforge.net/tracker/index.php?func=3Ddetail&aid=3D1831403&group_=
id=3D14&atid=3D100014 =

( uuid/blkid performance problem with large number of mounts )

so this won`t get lost.

regards
roland

Quoted 8 lines

-----Urspr=FCngliche Nachricht-----
Von: [email protected]
Gesendet: 02.11.07 20:06:58
An: Neil Brown <[email protected]>
CC: "J. Bruce Fields" <[email protected]>, [email protected]
Betreff: Re: [NFS] stale nfs file handle with exported loopback mounts

Quoted 6 lines

=
hi!
=
it seems i was having weird mail problems with sending mails trough my we=

bmailer - at least two followups with attachments seem to be lost on sendin= g and are not in my sent folder anymore....

Quoted 3 lines

=
anyway - here is a second try, but probably worse than what i have writte=

n before :)

Quoted 5 lines

=
=
first off, thanks for the patch Neil, things look _much_ better now and e=

xporting loopback mounts now basiscally works again.

Quoted 7 lines

nice to see that my posting helped finding bugs.
=
maybe i have two more bugs for you :)
=
i have loopback mounts on the server and exported the parent dir with cro=

ssmnt option.

Quoted 3 lines

=
after mounting for the first time on the client, i`m getting "Invalid arg=

ument" for each loopback-mounted dir, if i do an ls -la on /mnt.

Quoted 1 line

this only happens _once_ and seems to be a server problem, because i can =

reboot the client and remount , i never see that errors again.

Quoted 5 lines

=
besides that, all seems to work fine.
=

Quoted 7 lines

as neil suggested, i have made a tcpdump of this available at:
http://82.141.46.148/bugs/nfs/tcpdump.out.bz2
=
=
furthermore, there is a very strange performance issue i was able to trac=

k down to uuid/blkid support.

Quoted 3 lines

=
i recognized this issue when i exported a directory containing a very lar=

ge number of loopback mounts via crossmnt export option.

Quoted 1 line

ls -la on the clients mountpoint seemed to hung and i could see mountd be=

ing busy, eating 100% cpu for quite a while.

Quoted 3 lines

=
the time needed for ls to finish seems to grow exponentially with the num=

ber of loopback-mounts inside the exported directory - i also tried with 10= 00 loopback mounts and mountd being busy for several minutes with this.

Quoted 7 lines

=
i have made a strace of mountd available at:
http://82.141.46.148/bugs/nfs/mountd.strace.txt.bz2
=
you can see that mountd seems to be busy doing the same things over and o=

ver again, looks that it does stat64() for all devices in /etc/blkid.tab fo= r each loopback mount, weird.

Quoted 3 lines

=
here is some "strace -c -p $PID_OF_MOUNTD" for comparison - without uuid=

/blkid support compiled in it looks like this:

Quoted 167 lines

=
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 73.23    0.147722           2     66313           stat64
 10.37    0.020923          20      1031           write
  5.54    0.011179          23       494           select
  3.82    0.007699           5      1546           read
  3.04    0.006137           8       773           time
  2.18    0.004393           6       769           lstat64
  1.08    0.002182           4       519           munmap
  0.40    0.000797           1      1035           close
  0.29    0.000594           1      1034           open
  0.04    0.000089           0      1036           fstat64
  0.00    0.000000           0         2           alarm
  0.00    0.000000           0         3           _llseek
  0.00    0.000000           0         1           fdatasync
  0.00    0.000000           0         2           poll
  0.00    0.000000           0         2           rt_sigaction
  0.00    0.000000           0       521           mmap2
  0.00    0.000000           0         2           fcntl64
  0.00    0.000000           0         1           socket
  0.00    0.000000           0         1           connect
  0.00    0.000000           0         1           accept
  0.00    0.000000           0         2           send
------ ----------- ----------- --------- --------- ----------------
100.00 0.201715 75088 total
=
=
=
this is an strace -c when uuid/blkid support is being compiled in:
=
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
 61.64    1.008158           2    550916           stat64
 21.67    0.354441           9     37662           read
  5.65    0.092476          15      6377           getdents64
  4.06    0.066381           3     21395      8232 open
  1.62    0.026485           2     13169           fstat64
  1.36    0.022237           2     13164           close
  1.22    0.020025           2      8414           lstat64
  1.15    0.018805           4      4415           munmap
  0.27    0.004382          17       258           rename
  0.26    0.004329          17       258           unlink
  0.26    0.004305           2      2101           write
  0.23    0.003786           1      4380           fcntl64
  0.18    0.002899          11       262           select
  0.18    0.002883          11       258           access
  0.11    0.001857           0      4417           mmap2
  0.11    0.001765           0      4652           time
  0.01    0.000237           1       258           link
  0.00    0.000041           0       258           lseek
  0.00    0.000000           0         2           alarm
  0.00    0.000000           0         2           brk
  0.00    0.000000           0         1           gettimeofday
  0.00    0.000000           0       258           fchmod
  0.00    0.000000           0       265           _llseek
  0.00    0.000000           0         1           fdatasync
  0.00    0.000000           0         2           poll
  0.00    0.000000           0         1           prctl
  0.00    0.000000           0         2           rt_sigaction
  0.00    0.000000           0         1           getuid32
  0.00    0.000000           0         1           getgid32
  0.00    0.000000           0         1           geteuid32
  0.00    0.000000           0         1           getegid32
  0.00    0.000000           0         1           futex
  0.00    0.000000           0         1           socket
  0.00    0.000000           0         1           connect
  0.00    0.000000           0         1           accept
  0.00    0.000000           0         2           send
------ ----------- ----------- --------- --------- ----------------
100.00 1.635492 673158 8232 total
=
=
as you can see there is an unusual high number of stat64() calls =
server is opensuse 10.3 , client is suse 9.3 professional =
if i can help resolving this issue, tell me what to do :) =
regards
roland
=
=
=
Quoted 6 lines
-----Urspr=FCngliche Nachricht-----
Von: Neil Brown <[email protected]>
Gesendet: 01.11.07 05:26:50
An: [email protected]
CC: "J. Bruce Fields" <[email protected]>, [email protected]
Betreff: Re: [NFS] stale nfs file handle with exported loopback mounts
=
=
Quoted 59 lines
=
Quoted 7 lines · On Wednesday October 31, [email protected] wrote:
ok, i just wanted to tell that this isn`t the right way to go imho. =
some time ago i have tested exporting a parent dir containing several loopback mounted iso images with some pre-1.1.0 nfs-utils version and it worked - so =EC wonder why it now seems to have issues as things should have gone stable..... =
=
We have a way of breaking things sometimes.... It's called "progress". :-)
=
The short answer is that there is a bug in mountd which is fixed by this patch:
=
utils/mountd/cache.c +1 -1
index ce1a5a9..fd317cd 100644
@@ -508,7 +508,7 @@ void nfsd_fh(FILE *f)
 	 */
 	qword_printint(f, 0x7fffffff);
 	if (found)
-		qword_print(f, found->e_path);
+		qword_print(f, found_path);
 	qword_eol(f);
  out:
 	free(found_path);
=
=
The longer answer is that there is also a bug in "mount.nfs" which is unrelated but was slowing me down in chasing this bug, and there is also a bug in the NFS client which was causing my client oops and need a reboot every time I triggered this bug in mountd, which further slowed me down.
=
The effect of this bug in mountd is that when the NFS client calls GETATTR on the root of the subordinate filesystem (e.g. your loop-mounted isos), it got attr information about the parent. ie. the top-level exported filesystem (/export in your case I think). This has a different 'fsid' than the nfs client was expecting and the NFS client got confused in various ways.
=
Thanks for your problem report - it helped find 3 bugs! =
I'll get proper patches or bug report off to the relevant maintainers shortly.
=

Quoted 6 lines

Quoted 2 lines
NeilBrown
=
=
=

______________________________________________________________________
XXL-Speicher, PC-Virenschutz, Spartarife & mehr: Nur im WEB.DE Club! =

Jetzt testen! http://produkte.web.de/club/?mc=3D021130

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop. Now Search log events and configuration files using AJAX and a browser. Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

Neil Brown

2007-11-15 05:26 UTC #1 lore raw

Quoted 6 lines · On Tuesday November 13, [email protected] wrote:

since i posted 2 problems in one mail - and one problem is solved now, for the second problem i have opened a ticket at
http://sourceforge.net/tracker/index.php?func=detail&aid=1831403&group_id=14&atid=100014
( uuid/blkid performance problem with large number of mounts )
so this won`t get lost.

Unfortuantely that is a bit like saying "I've placed in the nice round filling cabinet so it won't get lost", not realising that the nice round filing cabinet is actually a garbage be.

No one (that I know of) looks at the issue tracker on sourceforge at all.

I have it on my personal "list of things to look at one day", so maybe it won't get forgotten.

thanks,
NeilBrown

Trond Myklebust

2007-11-15 17:23 UTC #2 lore raw

Quoted 12 lines · Neil Brown

Quoted 6 lines · On Tuesday November 13, [email protected] wrote:
since i posted 2 problems in one mail - and one problem is solved now, for the second problem i have opened a ticket at
http://sourceforge.net/tracker/index.php?func=detail&aid=1831403&group_id=14&atid=100014
( uuid/blkid performance problem with large number of mounts )
so this won`t get lost.
Unfortuantely that is a bit like saying "I've placed in the nice round filling cabinet so it won't get lost", not realising that the nice round filing cabinet is actually a garbage be.

Quoted 5 lines

No one (that I know of) looks at the issue tracker on sourceforge at all.
I have it on my personal "list of things to look at one day", so maybe it won't get forgotten.

Is it possible to turn this feature off on sourceforge? It is rather unfortunate that people take the time to type these things up, without realising that the tracker is unmonitored. It would be even better if we could display a message saying "please submit this to the mailing lists and/or bugzilla".

Cheers
Trond