Bug 251655

Summary: nfs-utils-1.1.0-1.fc8 + 2.6.23-0.61.rc1.git9.fc8: "is already mounted or busy"
Product: [Fedora] Fedora Reporter: Steven Shiau <steven>
Component: nfs-utilsAssignee: Steve Dickson <steved>
Status: CLOSED NOTABUG QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 8   
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2008-05-24 08:40:20 EDT Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Attachments:
Description Flags
network trace by tshark none

Description Steven Shiau 2007-08-10 05:25:39 EDT
Description of problem:
nfs-utils-1.1.0-1.fc8 does not work very well with 2.6.23-0.61.rc1.git9.fc8

Version-Release number of selected component (if applicable):


How reproducible:
Always

Steps to Reproduce:
1. Install Fedora 8 test1
2. Follow http://drbl.sf.net to install DRBL (Diskless Remote Boot in Linux),
use drblsrv-offline to install the required packages and the kernel for clients,
then run drblpush to deploy the files for clients.
3. Boot the clients via PXE
  
Actual results:
mount.nfs: /etc is already mounted or busy 
mount.nfs: /var is already mounted or busy 
mount.nfs: /usr is already mounted or busy 

Expected results:
mount.nfs successfully mount /etc, /var/, /usr

Additional info:
This also happened in Fedora 7, nfs-utils-1.1.0-1.fc7 + kernel-2.6.22.1-41.fc7,
if we change the kernel of the DRBL client to use kernel-2.6.21-1.3194.fc7, the
problem is gone, and it works very well.
Some similar or related posts:
http://lists.linuxcoding.com/rhl/2007q3/msg04551.html
http://sourceforge.net/forum/message.php?msg_id=4453745
Comment 1 Steven Shiau 2007-08-14 09:44:49 EDT
Now I can reproduce the same bug in Fedora core 6 with updated kernel
kernel-2.6.22.1-32.fc6. I guess the bug is in the kernel, not the nfs-utils.
Comment 2 Steven Shiau 2007-08-16 22:26:18 EDT
Tested with newer kernel 2.6.23-0.110.rc3.git1.fc8 in the nfs
(nfs-utils-1.1.0-4.fc8) client, the server is running with kernel
2.6.23-0.105.rc3.fc8 and nfs-utils-1.1.0-4.fc8. When client tried to mount, the
message in the server:
------------------------
Aug 17 18:18:02 f8b1 mountd[8050]: authenticated mount request from f8b1101:930
for /tftpboot/nodes/192.168.130.1/etc (/tftpboot/nodes/192.168.130.1)
------------------------
Apparently server got the request and allowed the client to mount.
The command ran in the client:
------------------------
strace /bin/mount -t nfs -n 192.168.130.254:/tftpboot/nodes/192.168.130.1/etc
/mnt -o rw,tcp,noloc
------------------------
and here the results are:
------------------------
execve("/bin/mount", ["/bin/mount", "-t", "nfs", "-n",
"192.168.130.254:/tftpboot/nodes/"..., "/mnt"..., "-o"..., "rw,tcp,nolock"...],
[/* 11 vars */]) = 0
brk(0)                                  = 0x877e000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=38337, ...}) = 0
mmap2(NULL, 38337, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fd1000
close(3)                                = 0
open("/lib/libblkid.so.1", O_RDONLY)    = 3
read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220\277m\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=38620, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fd0000
mmap2(0x6da000, 39824, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x6da000
mmap2(0x6e3000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x8) = 0x6e3000
close(3)                                = 0
open("/lib/libuuid.so.1", O_RDONLY)     = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@Jm\0004\0\0\0"..., 512)
= 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=11420, ...}) = 0
mmap2(0x6d4000, 12824, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x6d4000
mmap2(0x6d7000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x2) = 0x6d7000
close(3)                                = 0
open("/lib/libselinux.so.1", O_RDONLY)  = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\320)}\0004\0\0\0"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=105964, ...}) = 0
mmap2(0x7cf000, 109468, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7cf000
mmap2(0x7e8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x18) = 0x7e8000
close(3)                                = 0
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0Pb\1\0004\0\0\0"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1669208, ...}) = 0
mmap2(NULL, 1394128, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x12e000
mmap2(0x27d000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14f) = 0x27d000
mmap2(0x280000, 9680, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS,
-1, 0) = 0x280000
close(3)                                = 0
open("/lib/libdevmapper.so.1.02", O_RDONLY) = 3
read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\320:\230\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=87468, ...}) = 0
mmap2(0x981000, 88700, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x981000
mmap2(0x995000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x13) = 0x995000
close(3)                                = 0
open("/lib/libdl.so.2", O_RDONLY)       = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220\n\0\0004\0\0\0"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=18676, ...}) = 0
mmap2(NULL, 16504, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x283000
mmap2(0x286000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x2) = 0x286000
close(3)                                = 0
open("/lib/libsepol.so.1", O_RDONLY)    = 3
read(3,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@\177\325\0004\0\0\0"..., 512) = 512
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fcf000
fstat64(3, {st_mode=S_IFREG|0755, st_size=245504, ...}) = 0
mmap2(0xd55000, 285024, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0xd55000
mmap2(0xd90000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x3b) = 0xd90000
mmap2(0xd91000, 39264, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xd91000
close(3)                                = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fce000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7fce710, limit:1048575,
seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0,
useable:1}) = 0
mprotect(0x286000, 4096, PROT_READ)     = 0
mprotect(0x27d000, 8192, PROT_READ)     = 0
mprotect(0x12b000, 4096, PROT_READ)     = 0
munmap(0xb7fd1000, 38337)               = 0
brk(0)                                  = 0x877e000
brk(0x879f000)                          = 0x879f000
open("/etc/selinux/config", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=511, ...}) = 0
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fbe000
read(3, "# This file controls the state o"..., 65536) = 511
read(3, "", 65536)                      = 0
close(3)                                = 0
munmap(0xb7fbe000, 65536)               = 0
statfs64("/selinux", 84, 0xbf8980ac)    = -1 ENOENT (No such file or directory)
open("/proc/mounts", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fda000
read(3, "rootfs / rootfs rw 0 0\n192.168.1"..., 1024) = 278
read(3, "", 1024)                       = 0
close(3)                                = 0
munmap(0xb7fda000, 4096)                = 0
umask(022)                              = 022
open("/dev/null", O_RDWR|O_LARGEFILE)   = 3
close(3)                                = 0
getuid32()                              = 0
geteuid32()                             = 0
getgid32()                              = 0
getegid32()                             = 0
prctl(0x3, 0, 0, 0, 0)                  = 1
open("/etc/blkid/blkid.tab", O_RDONLY)  = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=867, ...}) = 0
fcntl64(3, F_GETFL)                     = 0 (flags O_RDONLY)
fstat64(3, {st_mode=S_IFREG|0644, st_size=867, ...}) = 0
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb7fbe000
_llseek(3, 0, [0], SEEK_CUR)            = 0
read(3, "<device DEVNO=\"0xfd01\" TIME=\"118"..., 65536) = 867
read(3, "", 65536)                      = 0
close(3)                                = 0
munmap(0xb7fbe000, 65536)               = 0
getuid32()                              = 0
geteuid32()                             = 0
stat64("/sbin/mount.nfs", {st_mode=S_IFREG|S_ISUID|0755, st_size=55456, ...}) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7fce758) = 1163
wait4(-1, mount.nfs: /mnt is already mounted or busy
[{WIFEXITED(s) && WEXITSTATUS(s) == 32}], 0, NULL) = 1163
--- SIGCHLD (Child exited) @ 0 (0) ---
exit_group(32)                          = ?
------------------------

If more info is required, please let me know.
Comment 3 Steven Shiau 2007-08-16 22:30:48 EDT
BTW, the results for "cat /proc/mounts" in the nfs client is:
------------------
rootfs / rootfs rw 0 0
192.168.130.254:/tftpboot/node_root / nfs
rw,relatime,vers=3,rsize=65536,wsize=65536,hard,nolock,proto=tcp,timeo=70,retrans=3,sec=sys,addr=192.168.130.254
0 0
none /proc proc rw,relatime 0 0
none /dev tmpfs rw,relatime 0 0
none /sys sysfs rw,relatime 0 0
------------------
Comment 4 Steve Dickson 2007-08-17 07:27:05 EDT
Would it be possible to get a network trace by doing something
similar to:

tshark -w /tmp/bz251655.pcap host <client> ; bzip2 /tmp/bz251655.pcap

Of course I'm assuming that the server is running Linux. If this
is not the case you can also use tcpdump but make you use
the -s0 flag, ala

tcpdump -s0 -w /tmp/bz251655.pcap host <client> ; bzip2 /tmp/bz251655.pcap
Comment 5 Steven Shiau 2007-08-17 10:41:41 EDT
Created attachment 161737 [details]
network trace by tshark

dump by this command:
tshark -w /tmp/bz251655.pcap -i eth1 host 192.168.130.1
Comment 6 Steven Shiau 2007-08-17 10:44:48 EDT
The NFS server is running kernel 2.6.23-0.105.rc3.fc8 and using
nfs-utils-1.1.0-4.fc8.  It's Fedora 8 test1 and was updated today.
Comment 7 Steven Shiau 2007-08-21 02:34:14 EDT
I found when the nfs client uses 2.6.23-0.110.rc3.git1.fc8, something shows in
the diskless client booting:
-------------------------------------------
...
mount used greatest stack depth: 724 bytes left
... 
cut used greatest stack depth: 544 bytes left
...
-------------------------------------------
Maybe this is related to this bug ?  544 bytes is dangerous...
BTW, the busybox used in the diskless client is 1.2.1.

However, the kernel config-2.6.18-1.2869.fc6 is also CONFIG_4KSTACKS=y, which
works for diskless client, no such problem.
Comment 8 Steven Shiau 2007-08-22 22:14:24 EDT
An update.
Just did a test in a NFS client with kernel 2.6.23-0.115.rc3.git1.fc8, and
nfs-utils is 1.1.0-4.fc8, the problem still exists.
Comment 9 Steven Shiau 2007-08-23 05:05:55 EDT
I recompiled 2.6.23-0.115.rc3.git with CONFIG_4KSTACKS is not set. Use the
complied kernel in the nfs client, Apparently I can see the stack is larger now
: "mount.nfs used greatest stack depth: 4552 bytes left".
However, I still encountered the same problem "is already mounted or busy".

Therefore I guess CONFIG_4KSTACKS=y is not the source of the problem.
Comment 10 Steve Dickson 2007-08-23 11:44:52 EDT
Try added the "nosharecache" mount option to your mounts, it just occured to
me we added some new mounting changes that you might be running into.
Comment 11 Steven Shiau 2007-08-24 02:42:51 EDT
BINGO!
That's the one! Thank you very much.
However, in the "man 5 nfs", it shows
 nosharecache   As  of kernel 2.6.18, it is no longer possi-
                      ble to mount the same same  filesystem  with
                      different mount options to a new mountpoint.
                      It was deemed unsafe to do so, since  cached
                      data cannot be shared between the two mount-
                      points. In consequence, files or directories
                      that were common to both mountpoint subtrees
                      could often be seen to be out of  sync  fol-
                      lowing an update.
                      This  option allows administrators to select
                      the  pre-2.6.18  behaviour,  permitting  the
                      same filesystem to be mounted with different
                      mount options.
                      Beware: Use of this  option  is  not  recom-
                      mended unless you are certain that there are
                      no hard links or subtrees of this mountpoint
                      that are mounted elsewhere.

It says it's after 2.6.18, but why I did not have such problem in those kernel
2.6.18-2.6.21 until 2.6.22 ?
Comment 12 Steve Dickson 2008-05-24 08:40:20 EDT
because thats when we added the super block sharing code...