Something seems to have broken in the nfs locking on kernel
2.4.4-6mdk. When I try to use something that needs locking I get the
following symptoms:
strace of process (testlk - tests locking) trying to lock a file (foo)
on an nfs filesystem (current filesystem is nfs mounted):
...
getpid() = 2753
open("foo", O_RDWR) = 3
shmat(3, 0x6, 0x6) = -1 ENOLCK (No locks available)
write(2, "fcntl: No locks available\n", 26fcntl: No locks available
) = 26
_exit(2) = ?
testlk.c is attached.
shmat() pauses for about 20-30 seconds and then returns ENOLCK. I
also get the following in my messages log when this happens:
May 27 13:23:24 pc kernel: statd: server localhost not responding, timed out
May 27 13:23:24 pc kernel: lockd: cannot monitor 10.75.2.2
May 27 13:23:24 pc kernel: lockd: failed to monitor 10.75.2.2
strace of rpc.statd running has interesting results:
2773 execve("/sbin/rpc.statd", ["/sbin/rpc.statd"], [/* 33 vars */]) = 0
2773 uname({sys="Linux", node="pc", ...}) = 0
2773 brk(0) = 0x804eaa0
2773 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40016000
2773 open("/etc/ld.so.preload", O_RDONLY) = 4
2773 fstat64(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
2773 close(4) = 0
2773 open("/etc/ld.so.cache", O_RDONLY) = 4
2773 fstat64(4, {st_mode=S_IFREG|0644, st_size=48091, ...}) = 0
2773 old_mmap(NULL, 48091, PROT_READ, MAP_PRIVATE, 4, 0) = 0x40017000
2773 close(4) = 0
2773 open("/lib/libnsl.so.1", O_RDONLY) = 4
2773 read(4, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0A\0\000"..., 1024) =
1024
2773 fstat64(4, {st_mode=S_IFREG|0755, st_size=79188, ...}) = 0
2773 old_mmap(NULL, 90560, PROT_READ|PROT_EXEC, MAP_PRIVATE, 4, 0) = 0x40023000
2773 mprotect(0x40036000, 12736, PROT_NONE) = 0
2773 old_mmap(0x40036000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 4,
0x12000) = 0x40036000
2773 old_mmap(0x40038000, 4544, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40038000
2773 close(4) = 0
2773 open("/lib/libc.so.6", O_RDONLY) = 4
2773 read(4, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0P\305\1"..., 1024) = 1024
2773 fstat64(4, {st_mode=S_IFREG|0755, st_size=1227104, ...}) = 0
2773 old_mmap(NULL, 1243464, PROT_READ|PROT_EXEC, MAP_PRIVATE, 4, 0) = 0x4003a000
2773 mprotect(0x40161000, 35144, PROT_NONE) = 0
2773 old_mmap(0x40161000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 4,
0x126000) = 0x40161000
2773 old_mmap(0x40166000, 14664, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40166000
2773 close(4) = 0
2773 munmap(0x40017000, 48091) = 0
2773 getpid() = 2773
2773 fork() = 2774
2774 setsid() = 2774
2774 chdir("/var/lib/nfs/statd/") = 0
2774 getrlimit(0x7, 0xbffff9f8, 0x400f4b90, 0x1, 0xbffff9f8) = 0
2774 close(0) = 0
2774 close(1) = 0
2774 close(2) = 0
2774 close(3) = 0
2774 close(4) = -1 EBADF (Bad file descriptor)
2774 close(5) = -1 EBADF (Bad file descriptor)
2774 close(6) = -1 EBADF (Bad file descriptor)
...
2774 close(302) = -1 EBADF (Bad file descriptor)
2773 _exit(0) = ?
2774 close(303) = -1 EBADF (Bad file descriptor)
...
2774 close(1022) = -1 EBADF (Bad file descriptor)
2774 close(1023) = -1 EBADF (Bad file descriptor)
2774 open("/dev/null", O_RDWR) = 0
2774 open("/dev/null", O_RDWR) = 1
2774 open("/dev/null", O_RDWR) = 2
2774 socket(PF_UNIX, SOCK_DGRAM, 0) = 3
2774 shmat(3, 0x2, 0x2) = ?
2774 connect(3, {sin_family=AF_UNIX, path=" /dev/log"}, 16) = 0
2774 getpid() = 2774
2774 brk(0) = 0x804eaa0
2774 brk(0x804ec30) = 0x804ec30
2774 brk(0x804f000) = 0x804f000
2774 brk(0x8052000) = 0x8052000
2774 time([990995594]) = 990995594
2774 open("/etc/localtime", O_RDONLY) = 4
2774 fstat64(4, {st_mode=S_IFREG|0644, st_size=1017, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40017000
2774 read(4, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0"..., 4096) = 1017
2774 close(4) = 0
2774 munmap(0x40017000, 4096) = 0
2774 getpid() = 2774
2774 rt_sigaction(SIGPIPE, {0x4011cff0, [], 0x4000000}, {SIG_DFL}, 8) = 0
2774 send(3, "<173>May 27 13:33:14 rpc.statd[2"..., 60, 0) = 60
2774 rt_sigaction(SIGPIPE, {SIG_DFL}, NULL, 8) = 0
2774 rt_sigaction(SIGHUP, {0x804b140, [HUP], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0
2774 rt_sigaction(SIGINT, {0x804b140, [INT], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0
2774 rt_sigaction(SIGTERM, {0x804b140, [TERM], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0
2774 rt_sigaction(SIGCHLD, {SIG_IGN}, {SIG_DFL}, 8) = 0
2774 SYS_199(0x40164b2c, 0x9, 0x40165780, 0x40163590, 0xbffffaa4) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_UDP) = 4
2774 getpid() = 2774
2774 bind(4, {sin_family=AF_INET, sin_port=htons(830),
sin_addr=inet_addr("0.0.0.0")}}, 16) = 0
2774 gettimeofday({990995594, 810445}, NULL) = 0
2774 getpid() = 2774
2774 open("/etc/resolv.conf", O_RDONLY) = 5
2774 fstat64(5, {st_mode=S_IFREG|0644, st_size=72, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40017000
2774 read(5, "search ilinx interlinx.bc.ca dyn"..., 4096) = 72
2774 read(5, "", 4096) = 0
2774 close(5) = 0
2774 munmap(0x40017000, 4096) = 0
2774 open("/etc/nsswitch.conf", O_RDONLY) = 5
2774 fstat64(5, {st_mode=S_IFREG|0644, st_size=1744, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40017000
2774 read(5, "#\n# /etc/nsswitch.conf\n#\n# An ex"..., 4096) = 1744
2774 read(5, "", 4096) = 0
2774 close(5) = 0
2774 munmap(0x40017000, 4096) = 0
2774 open("/etc/ld.so.cache", O_RDONLY) = 5
2774 fstat64(5, {st_mode=S_IFREG|0644, st_size=48091, ...}) = 0
2774 old_mmap(NULL, 48091, PROT_READ, MAP_PRIVATE, 5, 0) = 0x40017000
2774 close(5) = 0
2774 open("/lib/libnss_files.so.2", O_RDONLY) = 5
2774 read(5, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0`\"\0\000"..., 1024) =
1024
2774 fstat64(5, {st_mode=S_IFREG|0755, st_size=39380, ...}) = 0
2774 old_mmap(NULL, 42708, PROT_READ|PROT_EXEC, MAP_PRIVATE, 5, 0) = 0x4016a000
2774 mprotect(0x40174000, 1748, PROT_NONE) = 0
2774 old_mmap(0x40174000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 5,
0x9000) = 0x40174000
2774 close(5) = 0
2774 munmap(0x40017000, 48091) = 0
2774 open("/etc/hosts", O_RDONLY) = 5
2774 shmat(5, 0x1, 0x1) = ?
2774 shmat(5, 0x1, 0x2) = ?
2774 fstat64(5, {st_mode=S_IFREG|0644, st_size=716, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40017000
2774 _llseek(5, 0, [0], SEEK_CUR) = 0
2774 socket(PF_UNIX, SOCK_STREAM, 0) = 6
2774 connect(6, {sin_family=AF_UNIX, path="
/var/run/.nscd_socket"}, 110) = -1 ENOENT
(No such file or directory)
2774 close(6) = 0
2774 open("/etc/passwd", O_RDONLY) = 6
2774 shmat(6, 0x1, 0x1) = ?
2774 shmat(6, 0x1, 0x2) = ?
2774 fstat64(6, {st_mode=S_IFREG|0644, st_size=1851, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40018000
2774 read(6, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1851
2774 close(6) = 0
2774 munmap(0x40018000, 4096) = 0
2774 open("/etc/group", O_RDONLY) = 6
2774 shmat(6, 0x1, 0x1) = ?
2774 shmat(6, 0x1, 0x2) = ?
2774 fstat64(6, {st_mode=S_IFREG|0644, st_size=772, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40018000
2774 _llseek(6, 0, [0], SEEK_CUR) = 0
2774 read(6, "root:x:0:root\nbin:x:1:root,bin,d"..., 4096) = 772
2774 read(6, "", 4096) = 0
2774 close(6) = 0
2774 munmap(0x40018000, 4096) = 0
2774 open("/etc/ld.so.cache", O_RDONLY) = 6
2774 fstat64(6, {st_mode=S_IFREG|0644, st_size=48091, ...}) = 0
2774 old_mmap(NULL, 48091, PROT_READ, MAP_PRIVATE, 6, 0) = 0x40175000
2774 close(6) = 0
2774 open("/lib/libnss_nisplus.so.2", O_RDONLY) = 6
2774 read(6, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200 \0"..., 1024) = 1024
2774 fstat64(6, {st_mode=S_IFREG|0755, st_size=41084, ...}) = 0
2774 old_mmap(NULL, 44328, PROT_READ|PROT_EXEC, MAP_PRIVATE, 6, 0) = 0x40018000
2774 mprotect(0x40022000, 3368, PROT_NONE) = 0
2774 old_mmap(0x40022000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 6,
0x9000) = 0x40022000
2774 close(6) = 0
2774 munmap(0x40175000, 48091) = 0
2774 uname({sys="Linux", node="pc", ...}) = 0
2774 open("/var/nis/NIS_COLD_START", O_RDONLY) = -1 ENOENT (No such file or directory)
2774 open("/etc/ld.so.cache", O_RDONLY) = 6
2774 fstat64(6, {st_mode=S_IFREG|0644, st_size=48091, ...}) = 0
2774 old_mmap(NULL, 48091, PROT_READ, MAP_PRIVATE, 6, 0) = 0x40175000
2774 close(6) = 0
2774 open("/lib/libnss_nis.so.2", O_RDONLY) = 6
2774 read(6, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\360!\0"..., 1024) = 1024
2774 fstat64(6, {st_mode=S_IFREG|0755, st_size=40136, ...}) = 0
2774 old_mmap(NULL, 43320, PROT_READ|PROT_EXEC, MAP_PRIVATE, 6, 0) = 0x40181000
2774 mprotect(0x4018b000, 2360, PROT_NONE) = 0
2774 old_mmap(0x4018b000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 6,
0x9000) = 0x4018b000
2774 close(6) = 0
2774 munmap(0x40175000, 48091) = 0
2774 uname({sys="Linux", node="pc", ...}) = 0
2774 ipc_subcall(0x1, 0x804fa10, 0x40164b2c, 0x1) = 0
2774 msgctl(29, IPC_STAT, 0x40163590) = 0
2774 msgget(29, 0x2|02) = 0
2774 ipc_subcall(0x40164b2c, 0x2, 0x40165780, 0x40163590) = 29
2774 SYS_199(0x40164b2c, 0x2, 0x40165780, 0x40163590, 0xbffffaa4) = 29
2774 access(".", R_OK|W_OK|X_OK) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
2774 ioctl(6, SIOCGIFCONF, 0xbfffd988) = 0
2774 ioctl(6, SIOCGIFFLAGS, 0xbfffd990) = 0
2774 close(6) = 0
2774 gettimeofday({990995594, 825439}, NULL) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_UDP) = 6
2774 bind(6, {sin_family=AF_INET, sin_port=htons(831),
sin_addr=inet_addr("0.0.0.0")}}, 16) = -1 EACCES (Permission denied)
2774 ioctl(6, FIONBIO, [1]) = 0
2774 setsockopt(6, SOL_IP, 0xb /* IP_??? */, [1], 4) = 0
2774 sendto(6, "\n\201\263\306\0\0\0\0\0\0\0\2\0\1\206\240\0\0\0\2\0\0"..., 56, 0,
{sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, 16) = 56
2774 poll([{fd=6, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
2774 recvfrom(6, "\n\201\263\306\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 400, 0,
{sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, [16]) = 28
2774 close(6) = 0
2774 open("state", O_RDWR|O_CREAT, 0600) = 6
2774 read(6, "E\0\0\0", 4) = 4
2774 lseek(6, 0, SEEK_SET) = 0
2774 write(6, "G\0\0\0", 4) = 4
2774 fsync(6) = 0
2774 close(6) = 0
2774 uname({sys="Linux", node="pc", ...}) = 0
2774 socket(PF_UNIX, SOCK_STREAM, 0) = 6
2774 connect(6, {sin_family=AF_UNIX, path="
/var/run/.nscd_socket"}, 110) = -1 ENOENT
(No such file or directory)
2774 close(6) = 0
2774 open("/etc/host.conf", O_RDONLY) = 6
2774 fstat64(6, {st_mode=S_IFREG|0644, st_size=26, ...}) = 0
2774 old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x40175000
2774 read(6, "order hosts,bind\nmulti on\n", 4096) = 26
2774 read(6, "", 4096) = 0
2774 close(6) = 0
2774 munmap(0x40175000, 4096) = 0
2774 _llseek(5, 0, [0], SEEK_SET) = 0
2774 read(5, "#192.168.2.254\tlinux\t\tlinux.inte"..., 4096) = 716
2774 read(5, "", 4096) = 0
2774 close(5) = 0
2774 munmap(0x40017000, 4096) = 0
2774 stat64("sm", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
2774 stat64("sm.bak", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
2774 open("/dev/null", O_RDONLY|O_NONBLOCK|O_DIRECTORY) = -1 ENOTDIR (Not a directory)
2774 open("sm", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 5
2774 fstat64(5, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
2774 shmat(5, 0x40165780, 0x2) = ?
2774 brk(0x8054000) = 0x8054000
2774 ipc_subcall(0x5, 0x80511c0, 0x1000, 0x2) = 48
2774 ipc_subcall(0x5, 0x80511c0, 0x1000, 0x2) = 0
2774 close(5) = 0
2774 open("sm.bak", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 5
2774 fstat64(5, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
2774 shmat(5, 0x804f5e0, 0x2) = ?
2774 ipc_subcall(0x5, 0x80511c0, 0x1000, 0x2) = 48
2774 ipc_subcall(0x5, 0x80511c0, 0x1000, 0x2) = 0
2774 close(5) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_UDP) = 5
2774 bind(5, {sin_family=AF_INET, sin_port=htons(832),
sin_addr=inet_addr("0.0.0.0")}}, 16) = -1 EACCES (Permission denied)
2774 bind(5, {sin_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}},
16) = 0
2774 getsockname(5, {sin_family=AF_INET, sin_port=htons(32790),
sin_addr=inet_addr("0.0.0.0")}}, [16]) = 0
2774 setsockopt(5, SOL_IP, 0x8 /* IP_??? */, [1], 4) = 0
2774 getrlimit(0x7, 0xbffff918, 0xff, 0x40168340, 0xbffff918) = 0
2774 brk(0x8056000) = 0x8056000
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
2774 ioctl(6, SIOCGIFCONF, 0xbfffd908) = 0
2774 ioctl(6, SIOCGIFFLAGS, 0xbfffd910) = 0
2774 close(6) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_UDP) = 6
2774 bind(6, {sin_family=AF_INET, sin_port=htons(833),
sin_addr=inet_addr("0.0.0.0")}}, 16) = -1 EACCES (Permission denied)
2774 ioctl(6, FIONBIO, [1]) = 0
2774 setsockopt(6, SOL_IP, 0xb /* IP_??? */, [1], 4) = 0
2774 sendto(6, "`\203Lo\0\0\0\0\0\0\0\2\0\1\206\240\0\0\0\2\0\0\0\1\0\0"..., 56, 0,
{sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, 16) = 56
2774 poll([{fd=6, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
2774 recvfrom(6, "`\203Lo\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1"..., 400,
0, {sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, [16])
= 28
2774 close(6) = 0
2774 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 6
2774 bind(6, {sin_family=AF_INET, sin_port=htons(834),
sin_addr=inet_addr("0.0.0.0")}}, 16) = -1 EACCES (Permission denied)
2774 bind(6, {sin_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}},
16) = 0
2774 getsockname(6, {sin_family=AF_INET, sin_port=htons(32802),
sin_addr=inet_addr("0.0.0.0")}}, [16]) = 0
2774 listen(6, 2) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 7
2774 ioctl(7, SIOCGIFCONF, 0xbfffd908) = 0
2774 ioctl(7, SIOCGIFFLAGS, 0xbfffd910) = 0
2774 close(7) = 0
2774 socket(PF_INET, SOCK_DGRAM, IPPROTO_UDP) = 7
2774 bind(7, {sin_family=AF_INET, sin_port=htons(835),
sin_addr=inet_addr("0.0.0.0")}}, 16) = -1 EACCES (Permission denied)
2774 ioctl(7, FIONBIO, [1]) = 0
2774 setsockopt(7, SOL_IP, 0xb /* IP_??? */, [1], 4) = 0
2774 sendto(7, "~\342SW\0\0\0\0\0\0\0\2\0\1\206\240\0\0\0\2\0\0\0\1\0\0"..., 56, 0,
{sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, 16) = 56
2774 poll([{fd=7, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
2774 recvfrom(7, "~\342SW\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1"..., 400,
0, {sin_family=AF_INET, sin_port=htons(111), sin_addr=inet_addr("127.0.0.1")}}, [16])
= 28
2774 close(7) = 0
2774 select(1024, [4], NULL, NULL, NULL
Notice the interesting EACCESes when trying to bind to various ports
on 0.0.0.0.
Any ideas as to what is going on, other than a simply broken kernel?
b.
--
Brian J. Murrell
