On Thu, Sep 28, 2006 at 06:34:48PM +0200, Wilhelm Meier wrote:
> Am Donnerstag, 28. September 2006 16:42 schrieb Herbert Poetzl:
> > On Thu, Sep 28, 2006 at 08:03:29AM +0200, Wilhelm Meier wrote:
> > > Am Mittwoch, 27. September 2006 16:40 schrieb Herbert Poetzl:
> > > > > H242-meier vserver.nfs # sysctl -a | grep sun
> > > > > error: "Operation not permitted" reading key "net.ipv4.route.flush"
> > > > > sunrpc.tcp_slot_table_entries = 16
> > > > > sunrpc.udp_slot_table_entries = 16
> > > > > sunrpc.nlm_debug = 0
> > > > > sunrpc.nfsd_debug = 1
> > > > > sunrpc.nfs_debug = 0
> > > > > sunrpc.rpc_debug = 1
> > > >
> > > > different values here will enable different debug
> > > > output, I would prefer something like 65535 there
> > > > (which will enable full output)
> > >
> > > The setting on the nfs-server:
> > >
> > > H242-meier ~ # sysctl -a | grep sun
> > > error: "Operation not permitted" reading key "net.ipv4.route.flush"
> > > sunrpc.tcp_slot_table_entries = 16
> > > sunrpc.udp_slot_table_entries = 16
> > > sunrpc.nlm_debug = 0
> > > sunrpc.nfsd_debug = 65535
> > > sunrpc.nfs_debug = 0
> > > sunrpc.rpc_debug = 65535
> > > H242-meier ~ #
> > >
> > > The log on the nfs-server:
> > >
> > > Sep 28 07:55:31 H242-meier device vmnet1 entered promiscuous mode
> > > Sep 28 07:55:49 H242-meier rpc.mountd: MNT3(/home) called
> > > Sep 28 07:55:49 H242-meier rpc.mountd: authenticated mount request from
> > > vs01:1009 for /home (
> > > /home) Sep 28 07:55:50 H242-meier nfsd: exp_rootfh(/home [f235c628]
> > > *:hda2/2277377) Sep 28 07:55:50 H242-meier nfsd: fh_compose(exp
> > > 03:02/2277377 //home, ino=2277377)
> > > Sep 28 07:56:09 H242-meier device vmnet1 left promiscuous mode
> > >
> > > The settings on the vserver-host:
> > >
> > > gs ~ # sysctl -a | grep sun
> > > error: "Success" reading key "dev.parport.parport0.autoprobe3"
> > > error: "Success" reading key "dev.parport.parport0.autoprobe2"
> > > error: "Success" reading key "dev.parport.parport0.autoprobe1"
> > > error: "Success" reading key "dev.parport.parport0.autoprobe0"
> > > error: "Success" reading key "dev.parport.parport0.autoprobe"
> > > error: "Operation not permitted" reading key "net.ipv4.route.flush"
> > > sunrpc.max_resvport = 1023
> > > sunrpc.min_resvport = 650
> > > sunrpc.tcp_slot_table_entries = 16
> > > sunrpc.udp_slot_table_entries = 16
> > > sunrpc.nlm_debug = 0
> > > sunrpc.nfsd_debug = 0
> > > sunrpc.nfs_debug = 65535
> > > sunrpc.rpc_debug = 65535
> > > gs ~ #
> > >
> > >
> > > The log on the vserver-host:
> > >
> > > Sep 27 22:13:18 gs rpciod_up: users 0
> > > Sep 27 22:13:18 gs RPC: setting up tcp-ipv4 transport...
> > > Sep 27 22:13:18 gs RPC: created transport cf91b400 with 16 slots
> > > Sep 27 22:13:18 gs RPC: xprt_create_proto created xprt cf91b400
> > > Sep 27 22:13:18 gs RPC: creating nfs client for 192.168.39.1 (xprt
> > > cf91b400) Sep 27 22:13:18 gs RPC: destroying transport cf91b400
> > > Sep 27 22:13:18 gs RPC: xs_destroy xprt cf91b400
> > > Sep 27 22:13:18 gs RPC: disconnected transport cf91b400
> > > Sep 27 22:13:18 gs nfs_create_client: cannot create RPC client. Error
> > > = -812534784
> > > Sep 27 22:13:18 gs rpciod_down sema 1
> > > Sep 27 22:13:18 gs nfs_get_sb: bad mount version
> > >
> > > ( ^^^^^^^^^^^^^^^^)
> > > This doesn't semm to look good?
> > >
> > > Attached the tcpdump.
> > >
> > > > could you try with a v3,tcp mount too?
> > >
> > > The trace of the mount inside the vs:
> > >
> > > vs01 / # strace mount 192.168.39.1:/home /home -o nfsvers=3,nolock,tcp
> > > execve("/bin/mount",
> > > ["mount", "192.168.39.1:/home", "/home", "-o", "nfsvers=3,nolock,tcp"],
> > > [/* 26 vars */]) = 0
> > > uname({sys="Linux", node="vs01", ...}) = 0
> > > brk(0) = 0x8063000
> > > 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=12117, ...}) = 0
> > > mmap2(NULL, 12117, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f4e000
> > > 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\0\35\0"..., 512)
> > > = 512
> > > fstat64(3, {st_mode=S_IFREG|0755, st_size=28764, ...}) = 0
> > > mmap2(NULL, 30740, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0)
> > > = 0xb7f46000
> > > mmap2(0xb7f4d000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|
> > > MAP_DENYWRITE, 3, 0x6) = 0xb7f4d000
> > > 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\320\n\0"...,
> > > 512) = 512
> > > fstat64(3, {st_mode=S_IFREG|0755, st_size=9600, ...}) = 0
> > > mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
> > > = 0xb7f45000
> > > mmap2(NULL, 11544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0)
> > > = 0xb7f42000
> > > mmap2(0xb7f44000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|
> > > MAP_DENYWRITE, 3, 0x1) = 0xb7f44000
> > > 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\0\240T\1"..., 512)
> > > = 512
> > > fstat64(3, {st_mode=S_IFREG|0755, st_size=1220000, ...}) = 0
> > > mmap2(NULL, 1158452, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3,
> > > 0) = 0xb7e27000
> > > mmap2(0xb7f3c000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|
> > > MAP_DENYWRITE, 3, 0x115) = 0xb7f3c000
> > > mmap2(0xb7f40000, 7476, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|
> > > MAP_ANONYMOUS, -1, 0) = 0xb7f40000
> > > close(3) = 0
> > > mprotect(0xb7f3c000, 4096, PROT_READ) = 0
> > > mprotect(0xb7f64000, 4096, PROT_READ) = 0
> > > munmap(0xb7f4e000, 12117) = 0
> > > open("/dev/urandom", O_RDONLY) = 3
> > > read(3, "\272\322(\335", 4) = 4
> > > close(3) = 0
> > > brk(0) = 0x8063000
> > > brk(0x8084000) = 0x8084000
> > > open("/dev/null", O_RDWR|O_LARGEFILE) = 3
> > > close(3) = 0
> > > getuid32() = 0
> > > geteuid32() = 0
> > > getgid32() = 0
> > > getegid32() = 0
> > > prctl(0x3, 0x20, 0xbfad7468, 0x5, 0xbfad7624) = 1
> > > open("/etc/blkid.tab", O_RDONLY) = -1 ENOENT (No such file or
> > > directory)
> > > getuid32() = 0
> > > geteuid32() = 0
> > > lstat64("/etc/mtab", {st_mode=S_IFREG|0644, st_size=298, ...}) = 0
> > > stat64("192.168.39.1:/home", 0xbfad73c0) = -1 ENOENT (No such file or
> > > directory)
> > > stat64("/sbin/mount.nfs", 0xbfad72b0) = -1 ENOENT (No such file or
> > > directory)
> > > uname({sys="Linux", node="vs01", ...}) = 0
> > > time(NULL) = 1159387997
> > > socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
> > > getpid() = 13128
> > > bind(3, {sa_family=AF_INET, sin_port=htons(1008),
> > > sin_addr=inet_addr("0.0.0.0")}, 16) = 0
> > > connect(3, {sa_family=AF_INET, sin_port=htons(111),
> > > sin_addr=inet_addr("192.168.39.1")}, 16) = 0
> > > gettimeofday({1159387997, 896879}, NULL) = 0
> > > write(3, "\200\0\0(\20\232d\23\0\0\0\0\0\0\0\2\0\1\206\240\0\0\0"..., 44)
> > > = 44 poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 60000) = 1
> > > read(3, "\0\0\1\214\20\232d\23\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > 500) = 500
> > > poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 60000) = 1
> > > read(3, "\0\0\0\3\0\0\0\6\0\0\2\371\0\0\0\0", 500) = 16
> > > close(3) = 0
> > > socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
> > > bind(3, {sa_family=AF_INET, sin_port=htons(1009),
> > > sin_addr=inet_addr("0.0.0.0")}, 16) = 0
> > > connect(3, {sa_family=AF_INET, sin_port=htons(761),
> > > sin_addr=inet_addr("192.168.39.1")}, 16) = 0
> > > uname({sys="Linux", node="vs01", ...}) = 0
> > > geteuid32() = 0
> > > getegid32() = 0
> > > getgroups32(0, NULL) = 11
> > > getgroups32(11, [0, 1, 2, 3, 4, 6, 10, 11, 20, 26, 27]) = 11
> > > gettimeofday({1159387997, 908258}, NULL) = 0
> > > write(3, "\200\0\0x\\\361\30\1\0\0\0\0\0\0\0\2\0\1\206\245\0\0\0"...,
> > > 124) = 124
> > > poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 20000) = 1
> > > read(3, "\200\0\0008\\\361\30\1\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0"...,
> > > 4000) = 60
> > > socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 4
> > > bind(4, {sa_family=AF_INET, sin_port=htons(1010),
> > > sin_addr=inet_addr("0.0.0.0")}, 16) = 0
> > > socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
> > > bind(5, {sa_family=AF_INET, sin_port=htons(1011),
> > > sin_addr=inet_addr("0.0.0.0")}, 16) = 0
> > > connect(5, {sa_family=AF_INET, sin_port=htons(111),
> > > sin_addr=inet_addr("192.168.39.1")}, 16) = 0
> > > write(5, "\200\0\0008,\225\237\267\0\0\0\0\0\0\0\2\0\1\206\240\0"..., 60)
> > > = 60 poll([{fd=5, events=POLLIN, revents=POLLIN}], 1, 60000) = 1
> > > read(5, "\200\0\0\34,\225\237\267\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 400)
> > > = 32 close(5) = 0
> > > uname({sys="Linux", node="vs01", ...}) = 0
> > > close(3) = 0
> > > close(3) = -1 EBADF (Bad file descriptor)
> > > rt_sigprocmask(SIG_BLOCK, ~[TRAP SEGV], NULL, 8) = 0
> > > mount("192.168.39.1:/home", "/home", "nfs", MS_MGC_VAL, "\4") = -1 EPERM
> > > (Operation not permitted)
> > > rt_sigprocmask(SIG_UNBLOCK, ~[TRAP SEGV], NULL, 8) = 0
> > > write(2, "NFSv3 not supported!\n", 21NFSv3 not supported!
> >
> > ~~~~~~~~~~~~~~~~~~~~~~~~~
> >
> > well, looks like your server does not support v3
> > (or the client's mount tools fail to provide that)
>
> No, the server supports v3:
>
> H242-meier ~ # zgrep NFS /proc/config.gz
> CONFIG_NFS_FS=y
> CONFIG_NFS_V3=y
> # CONFIG_NFS_V3_ACL is not set
> CONFIG_NFS_V4=y
> # CONFIG_NFS_DIRECTIO is not set
> CONFIG_NFSD=y
> CONFIG_NFSD_V3=y
> # CONFIG_NFSD_V3_ACL is not set
> # CONFIG_NFSD_V4 is not set
> CONFIG_NFSD_TCP=y
> CONFIG_NFS_COMMON=y
> # CONFIG_NCPFS_NFS_NS is not set
> H242-meier ~ #
>
> and mounting from the nfs-server to the vserver-host with nfs v3 ist fine,
> since the host supports also v3:
>
> gs ~ # zgrep NFS /proc/config.gz
> CONFIG_NFS_FS=y
> CONFIG_NFS_V3=y
> # CONFIG_NFS_V3_ACL is not set
> # CONFIG_NFS_V4 is not set
> # CONFIG_NFS_DIRECTIO is not set
> CONFIG_NFSD=y
> CONFIG_NFSD_V3=y
> # CONFIG_NFSD_V3_ACL is not set
> # CONFIG_NFSD_V4 is not set
> CONFIG_NFSD_TCP=y
> CONFIG_NFS_COMMON=y
> # CONFIG_NCPFS_NFS_NS is not set
> # CONFIG_TAG_NFSD is not set
> gs ~ #
>
> If I chroot to the vs-root mounting is also ok:
>
> gs ~ #
> gs ~ # chroot /vservers/vs01
> gs / # mount 192.168.39.1:/home /home -o nfsvers=3,tcp,nolock
> gs / #
>
> Strange?
strange indeed, okay, I will setup a test scenario
shortly, hopefully we will gain more insight then
best,
Herbert
> > I would double check that, as v3 mounts are currently
> > the only tested ones (for tcp and partially for udp,
> > which is of dubious value)
> >
> > please double check that the tools and the server
> > are capable of doing/providing v3 mounts and that
> > tcp is enabled too, then let's retry with a chroot
> > on the host (using the guest tools) and within the
> > guest, to see if there is a difference
> >
> > TIA,
> > Herbert
> >
> > > ) = 21
> > > rt_sigprocmask(SIG_BLOCK, ~[TRAP SEGV], NULL, 8) = 0
> > > mount("192.168.39.1:/home", "/home", "nfs", MS_MGC_VAL, "") = -1 EINVAL
> > > (Invalid argument)
> > > rt_sigprocmask(SIG_UNBLOCK, ~[TRAP SEGV], NULL, 8) = 0
> > > write(2, "mount: wrong fs type, bad option"..., 111mount: wrong fs type,
> > > bad option, bad superblock on 192.168.39.1:/home,
> > > missing codepage or other error
> > > ) = 111
> > > stat64("192.168.39.1:/home", 0xbfad7310) = -1 ENOENT (No such file or
> > > directory)
> > > write(2, " In some cases useful info"..., 86 In some cases
> > > useful info is found in syslog - try
> > > dmesg | tail or so
> > >
> > > ) = 86
> > > exit_group(32) = ?
> > > Process 13128 detached
> > > vs01 / #
> > >
> > >
> > > HTH,
> > > Wilhelm
> > >
> > > 07:55:49.937932 IP vs01.1008 > h242-meier-1.sunrpc: S
> > > 638026099:638026099(0) win 5840 <mss 1460,sackOK,timestamp 1782618[|tcp]>
> > > 07:55:49.955931 IP h242-meier-1.sunrpc > vs01.1008: S
> > > 1737240269:1737240269(0) ack 638026100 win 5792 <mss
> > > 1460,sackOK,timestamp 4375398[|tcp]> 07:55:49.955955 IP vs01.1008 >
> > > h242-meier-1.sunrpc: . ack 1 win 730 <nop,nop,timestamp 1782618 4375398>
> > > 07:55:49.955965 IP vs01.1008 > h242-meier-1.sunrpc: P 1:45(44) ack 1 win
> > > 730 <nop,nop,timestamp 1782618 4375398> 07:55:49.955976 IP
> > > h242-meier-1.sunrpc > vs01.1008: . ack 45 win 1448 <nop,nop,timestamp
> > > 4375398 1782618> 07:55:49.938151 IP h242-meier-1.sunrpc > vs01.1008: P
> > > 1:401(400) ack 45 win 1448 <nop,nop,timestamp 4375398 1782618>
> > > 07:55:49.938896 IP vs01.1008 > h242-meier-1.sunrpc: . ack 401 win 864
> > > <nop,nop,timestamp 1782619 4375398> 07:55:49.938908 IP
> > > h242-meier-1.sunrpc > vs01.1008: P 401:517(116) ack 45 win 1448
> > > <nop,nop,timestamp 4375398 1782619> 07:55:49.938975 IP vs01.1008 >
> > > h242-meier-1.sunrpc: . ack 517 win 864 <nop,nop,timestamp 1782619
> > > 4375398> 07:55:49.943725 IP vs01.1008 > h242-meier-1.sunrpc: F 45:45(0)
> > > ack 517 win 864 <nop,nop,timestamp 1782620 4375398> 07:55:49.945060 IP
> > > vs01.1009 > h242-meier-1.761: S 636815029:636815029(0) win 5840 <mss
> > > 1460,sackOK,timestamp 1782621[|tcp]> 07:55:49.945079 IP h242-meier-1.761
> > > > vs01.1009: S 1745412483:1745412483(0) ack 636815030 win 5792 <mss
> > > 1460,sackOK,timestamp 4375399[|tcp]> 07:55:49.945144 IP vs01.1009 >
> > > h242-meier-1.761: . ack 1 win 730 <nop,nop,timestamp 1782621 4375399>
> > > 07:55:49.947434 IP vs01.1009 > h242-meier-1.761: P 1:125(124) ack 1 win
> > > 730 <nop,nop,timestamp 1782621 4375399> 07:55:49.947444 IP
> > > h242-meier-1.761 > vs01.1009: . ack 125 win 1448 <nop,nop,timestamp
> > > 4375399 1782621> 07:55:49.951286 IP h242-meier-1.sunrpc > vs01.1008: F
> > > 517:517(0) ack 46 win 1448 <nop,nop,timestamp 4375400 1782620>
> > > 07:55:49.951410 IP vs01.1008 > h242-meier-1.sunrpc: . ack 518 win 864
> > > <nop,nop,timestamp 1782622 4375400> 07:55:50.072653 IP h242-meier-1.761 >
> > > vs01.1009: P 1:61(60) ack 125 win 1448 <nop,nop,timestamp 4375412
> > > 1782621> 07:55:50.072931 IP vs01.1009 > h242-meier-1.761: . ack 61 win
> > > 730 <nop,nop,timestamp 1782643 4375412> 07:55:50.075634 IP vs01.1011 >
> > > h242-meier-1.sunrpc: S 640167369:640167369(0) win 5840 <mss
> > > 1460,sackOK,timestamp 1782643[|tcp]> 07:55:50.075653 IP
> > > h242-meier-1.sunrpc > vs01.1011: S 1745740107:1745740107(0) ack 640167370
> > > win 5792 <mss 1460,sackOK,timestamp 4375412[|tcp]> 07:55:50.075729 IP
> > > vs01.1011 > h242-meier-1.sunrpc: . ack 1 win 730 <nop,nop,timestamp
> > > 1782643 4375412> 07:55:50.076153 IP vs01.1011 > h242-meier-1.sunrpc: P
> > > 1:61(60) ack 1 win 730 <nop,nop,timestamp 1782643 4375412>
> > > 07:55:50.076163 IP h242-meier-1.sunrpc > vs01.1011: . ack 61 win 1448
> > > <nop,nop,timestamp 4375412 1782643> 07:55:50.076855 IP
> > > h242-meier-1.sunrpc > vs01.1011: P 1:33(32) ack 61 win 1448
> > > <nop,nop,timestamp 4375412 1782643> 07:55:50.077703 IP vs01.1011 >
> > > h242-meier-1.sunrpc: . ack 33 win 730 <nop,nop,timestamp 1782644 4375412>
> > > 07:55:50.078749 IP vs01.1011 > h242-meier-1.sunrpc: F 61:61(0) ack 33 win
> > > 730 <nop,nop,timestamp 1782644 4375412> 07:55:50.080544 IP vs01.1009 >
> > > h242-meier-1.761: F 125:125(0) ack 61 win 730 <nop,nop,timestamp 1782644
> > > 4375412> 07:55:50.081799 IP h242-meier-1.sunrpc > vs01.1011: F 33:33(0)
> > > ack 62 win 1448 <nop,nop,timestamp 4375413 1782644> 07:55:50.081958 IP
> > > vs01.1011 > h242-meier-1.sunrpc: . ack 34 win 730 <nop,nop,timestamp
> > > 1782644 4375413> 07:55:50.092418 IP h242-meier-1.761 > vs01.1009: F
> > > 61:61(0) ack 126 win 1448 <nop,nop,timestamp 4375414 1782644>
> > > 07:55:50.092843 IP vs01.1009 > h242-meier-1.761: . ack 62 win 730
> > > <nop,nop,timestamp 1782647 4375414>
>
> --
> Wilhelm Meier
> email: wilhelm.meier@fh-kl.de
_______________________________________________
Vserver mailing list
Vserver@list.linux-vserver.org
http://list.linux-vserver.org/mailman/listinfo/vserver
Received on Thu Sep 28 18:35:41 2006