Stephan Windmüller wrote: > -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA1 > > On 24.10.2011 00:58, Jamie Heilman wrote: > > >> In my configuration both domains (client and server) are > >> correctly set, but this is not the issue: passwd and group data > >> is fetched from ldap as set in nsswitch.conf, but idmapd does not > >> seem to respect these settings. > > Then to figure out the issue you face we'll need a good deal more > > information about your setup I wager. You say you downgraded to > > nfs-common 1.2.2 and it fixed things ... > > No, the client is running squeeze so 1.2.2 was the only version I used.
OK, this should arguably be a different bug report then as your issue doesn't appear to be a post-stable regression. > > Have you tried to strace rpc.idmapd to determine what values it's > > using during the lookups? > > No, I did not try that. It may be worth trying. Here's what I see stracing my (working) rpc.idmapd on a Debian 6 nfs4 client (nfs-common 1:1.2.2-4) talking to a Debian Sid server: [67]canarsie<~/>sudo ls -l /proc/1497/fd total 0 lrwx------ 1 root root 64 Oct 30 19:08 0 -> /dev/null lrwx------ 1 root root 64 Oct 30 19:08 1 -> /dev/null lrwx------ 1 root root 64 Oct 30 19:08 11 -> socket:[17299] lrwx------ 1 root root 64 Oct 30 19:08 2 -> /dev/null lrwx------ 1 root root 64 Oct 30 19:08 3 -> anon_inode:[eventpoll] lrwx------ 1 root root 64 Oct 30 19:08 5 -> socket:[1723] lrwx------ 1 root root 64 Oct 30 19:08 6 -> socket:[1724] lrwx------ 1 root root 64 Oct 30 19:08 7 -> /proc/1497/net/rpc/nfs4.nametoid/channel lrwx------ 1 root root 64 Oct 30 19:08 8 -> /proc/1497/net/rpc/nfs4.idtoname/channel lr-x------ 1 root root 64 Oct 30 19:08 9 -> /var/lib/nfs/rpc_pipefs/nfs [68]canarsie<~/>sudo strace -s 50 -f -p 1497 ... epoll_wait(3, 805afc0, 32, -1) = -1 EINTR (Interrupted system call) --- SIGUSR1 (User defined signal 1) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) clock_gettime(CLOCK_MONOTONIC, {296845, 413152888}) = 0 open("/var/lib/nfs/rpc_pipefs/nfs", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 4 getdents(4, /* 3 entries */, 32768) = 52 getdents(4, /* 0 entries */, 32768) = 0 close(4) = 0 open("/var/lib/nfs/rpc_pipefs/nfs/clnt29", O_RDONLY) = 4 open("/var/lib/nfs/rpc_pipefs/nfs/clnt29/idmap", O_RDWR) = -1 ENOENT (No such file or directory) fcntl64(4, F_SETSIG, 0xc) = 0 fcntl64(4, F_NOTIFY, DN_CREATE|DN_DELETE|DN_MULTISHOT) = 0 epoll_wait(3, {{EPOLLIN, {u32=6, u64=6}}}, 32, -1) = 1 clock_gettime(CLOCK_MONOTONIC, {296845, 416977043}) = 0 recv(6, "a", 1, 0) = 1 epoll_wait(3, 805afc0, 32, -1) = -1 EINTR (Interrupted system call) --- SIGUSR2 (User defined signal 2) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) clock_gettime(CLOCK_MONOTONIC, {296845, 420593293}) = 0 open("/var/lib/nfs/rpc_pipefs/nfs/clnt29/idmap", O_RDWR) = 10 epoll_ctl(3, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 fcntl64(4, F_SETSIG, 0) = 0 fcntl64(4, F_NOTIFY, 0) = 0 epoll_wait(3, {{EPOLLIN, {u32=6, u64=6}}}, 32, -1) = 1 clock_gettime(CLOCK_MONOTONIC, {296845, 421892590}) = 0 recv(6, "a", 1, 0) = 1 epoll_wait(3, 805afc0, 32, -1) = -1 EINTR (Interrupted system call) --- SIGUSR1 (User defined signal 1) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) clock_gettime(CLOCK_MONOTONIC, {296845, 424126540}) = 0 open("/var/lib/nfs/rpc_pipefs/nfs", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 12 getdents(12, /* 4 entries */, 32768) = 72 getdents(12, /* 0 entries */, 32768) = 0 close(12) = 0 open("/var/lib/nfs/rpc_pipefs/nfs/clnt2a", O_RDONLY) = 12 open("/var/lib/nfs/rpc_pipefs/nfs/clnt2a/idmap", O_RDWR) = -1 ENOENT (No such file or directory) fcntl64(12, F_SETSIG, 0xc) = 0 fcntl64(12, F_NOTIFY, DN_CREATE|DN_DELETE|DN_MULTISHOT) = 0 epoll_wait(3, {{EPOLLIN, {u32=10, u64=10}}, {EPOLLIN, {u32=6, u64=6}}}, 32, -1) = 2 clock_gettime(CLOCK_MONOTONIC, {296845, 426810897}) = 0 epoll_ctl(3, EPOLL_CTL_DEL, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 read(10, "\0\1r...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 13 fstat64(13, {st_mode=S_IFREG|0644, st_size=1717, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb772f000 read(13, "root:x:0:0:root:/root:/bin/bash\ndaemon:x:1:1:daemo"..., 4096) = 1717 close(13) = 0 munmap(0xb772f000, 4096) = 0 write(10, "\0\1r...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 epoll_ctl(3, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 recv(6, "a", 1, 0) = 1 epoll_wait(3, {{EPOLLIN, {u32=10, u64=10}}}, 32, -1) = 1 clock_gettime(CLOCK_MONOTONIC, {296845, 430710301}) = 0 epoll_ctl(3, EPOLL_CTL_DEL, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 read(10, "\1\1r...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 open("/etc/group", O_RDONLY|O_CLOEXEC) = 13 fstat64(13, {st_mode=S_IFREG|0644, st_size=702, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb772f000 read(13, "root:x:0:\ndaemon:x:1:\nbin:x:2:\nsys:x:3:\nadm:x:4:be"..., 4096) = 702 close(13) = 0 munmap(0xb772f000, 4096) = 0 write(10, "\1\1r...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 epoll_ctl(3, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 epoll_wait(3, 805afc0, 32, -1) = -1 EINTR (Interrupted system call) --- SIGUSR1 (User defined signal 1) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) --- SIGUSR1 (User defined signal 1) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) --- SIGUSR2 (User defined signal 2) @ 0 (0) --- send(5, "a", 1, 0) = 1 sigreturn() = ? (mask now []) clock_gettime(CLOCK_MONOTONIC, {296845, 445160798}) = 0 open("/var/lib/nfs/rpc_pipefs/nfs", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 13 getdents(13, /* 4 entries */, 32768) = 72 getdents(13, /* 0 entries */, 32768) = 0 close(13) = 0 open("/var/lib/nfs/rpc_pipefs/nfs/clnt2b", O_RDONLY) = 13 open("/var/lib/nfs/rpc_pipefs/nfs/clnt2b/idmap", O_RDWR) = -1 ENOENT (No such file or directory) fcntl64(13, F_SETSIG, 0xc) = 0 fcntl64(13, F_NOTIFY, DN_CREATE|DN_DELETE|DN_MULTISHOT) = 0 close(-1) = -1 EBADF (Bad file descriptor) close(12) = 0 open("/var/lib/nfs/rpc_pipefs/nfs", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 12 getdents(12, /* 4 entries */, 32768) = 72 getdents(12, /* 0 entries */, 32768) = 0 close(12) = 0 open("/var/lib/nfs/rpc_pipefs/nfs/clnt2b/idmap", O_RDWR) = -1 ENOENT (No such file or directory) fcntl64(13, F_SETSIG, 0xc) = 0 fcntl64(13, F_NOTIFY, DN_CREATE|DN_DELETE|DN_MULTISHOT) = 0 epoll_wait(3, {{EPOLLIN, {u32=6, u64=6}}, {EPOLLIN, {u32=10, u64=10}}}, 32, -1) = 2 clock_gettime(CLOCK_MONOTONIC, {296845, 450728846}) = 0 recv(6, "a", 1, 0) = 1 epoll_ctl(3, EPOLL_CTL_DEL, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 read(10, "\0\1mu...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 12 fstat64(12, {st_mode=S_IFREG|0644, st_size=1717, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb772f000 read(12, "root:x:0:0:root:/root:/bin/bash\ndaemon:x:1:1:daemo"..., 4096) = 1717 read(12, "", 4096) = 0 close(12) = 0 munmap(0xb772f000, 4096) = 0 time(NULL) = 1320001875 send(11, "<28>Oct 30 19:11:15 rpc.idmapd[1497]: nss_getpwnam"..., 109, MSG_NOSIGNAL) = 109 write(2, "rpc.idmapd: ", 12) = 12 write(2, "nss_getpwnam: name 'music' not found in domain 'au"..., 71) = 71 write(2, "\n", 1) = 1 write(10, "\0\1mu...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 epoll_ctl(3, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 epoll_wait(3, {{EPOLLIN, {u32=6, u64=6}}, {EPOLLIN, {u32=10, u64=10}}}, 32, -1) = 2 clock_gettime(CLOCK_MONOTONIC, {296845, 456418870}) = 0 recv(6, "a", 1, 0) = 1 epoll_ctl(3, EPOLL_CTL_DEL, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 read(10, "\1\1mu...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 open("/etc/group", O_RDONLY|O_CLOEXEC) = 12 fstat64(12, {st_mode=S_IFREG|0644, st_size=702, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb772f000 read(12, "root:x:0:\ndaemon:x:1:\nbin:x:2:\nsys:x:3:\nadm:x:4:be"..., 4096) = 702 close(12) = 0 munmap(0xb772f000, 4096) = 0 write(10, "\1\1mu...@audible.transient.net\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 140) = 140 epoll_ctl(3, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0 epoll_wait(3, {{EPOLLIN, {u32=6, u64=6}}}, 32, -1) = 1 clock_gettime(CLOCK_MONOTONIC, {296845, 464423185}) = 0 recv(6, "a", 1, 0) = 1 epoll_wait(3, ^C <unfinished ...> That's the result of my automounter getting tickled and mounting (with options vers=4,ro) a share of music (exported with options: ro,async,subtree_check,all_squash). As you can see, I don't actually have a "music" user in my password database so rpc.idmapd ends up carping about that (though that ultimately doesn't matter as it's a read-only export and all squashed to nobody anyway). The files appear as owned by uid 65534 and gid 999 (which is my "music" group, and does exist in my group database). Another possibly interesting thing to check, the mapped libs rpc.idmapd are using are the ones I'd expect it to given my config which I checked via: root@canarsie:~# awk '$0 ~ "/" {print $6}' /proc/1497/smaps | sort -u /lib/i686/cmov/libc-2.11.2.so /lib/i686/cmov/libdl-2.11.2.so /lib/i686/cmov/libnsl-2.11.2.so /lib/i686/cmov/libnss_files-2.11.2.so /lib/i686/cmov/libpthread-2.11.2.so /lib/i686/cmov/libresolv-2.11.2.so /lib/i686/cmov/librt-2.11.2.so /lib/ld-2.11.2.so /usr/lib/libevent-1.4.so.2.1.3 /usr/lib/libnfsidmap.so.0.3.0 /usr/lib/libnfsidmap/nsswitch.so /usr/sbin/rpc.idmapd Here's the ltrace output of rpc.idmapd during the same operation: --- SIGUSR1 (User defined signal 1) --- unexpected breakpoint at 0xb7735423 scandir(0x804f460, 0xbfc649bc, 0, 0x8049128, 0x805b85b <unfinished ...> alphasort(0x805b7f4, 0x805b7f8, 0, 0xb7711000, 0xb75d26d4) = -1 alphasort(0x805b7f0, 0x805b7f4, 0, 1, 0xbfc6386c) = -1 <... scandir resumed> ) = 3 calloc(1, 4224) = 0x0805b8e0 snprintf("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 4096, "%s/%s", "/var/lib/nfs/rpc_pipefs/nfs", "clnt2f") = 34 open("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 0, 00) = 4 open("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 2, 00 <unfinished ...> --- SIGUSR1 (User defined signal 1) --- unexpected breakpoint at 0x8048ee7 --- SIGUSR1 (User defined signal 1) --- unexpected breakpoint at 0x8048ee7 open("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 2, 00) = 10 event_set(0x805c910, 10, 2, 0x804a1e0, 0x805b8e0) = 0 event_add(0x805c910, 0, 2, 0x804a1e0, 0x805b8e0) = 0 fcntl(4, 10, 0, 0x804a1e0, 0x805b8e0) = 0 fcntl(4, 1026, 0, 0x804a1e0, 0x805b8e0) = 0 free(0x0805b820) = <void> free(0x0805b838) = <void> free(0x0805b850) = <void> free(0x0805b7f0) = <void> scandir(0x804f460, 0xbfc649bc, 0, 0x8049128, 0x805b85b <unfinished ...> alphasort(0x805b7f0, 0x805b7f4, 0, 0xb7711000, 0xb75d26d4) = -1 alphasort(0x805b7f8, 0x805b7fc, 0, 0xb7711000, 0xb75d26d4) = 1 alphasort(0x805b7f0, 0x805b7f8, 0, 1, 0xbfc6386c) = -1 alphasort(0x805b7f4, 0x805b7f8, 0, 1, 0xbfc6386c) = -1 <... scandir resumed> ) = 4 strcmp("2f", "2f") = 0 strcmp("31", "2f") = 1 calloc(1, 4224) = 0x0805c968 snprintf("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 4096, "%s/%s", "/var/lib/nfs/rpc_pipefs/nfs", "clnt31") = 34 open("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 0, 00) = 12 open("/var/lib/nfs/rpc_pipefs/nfs/clnt"..., 2, 00) = -1 __errno_location() = 0xb7578688 fcntl(12, 10, 12, 0x805c968, 0xb770cff4) = 0 fcntl(12, 1026, 0x8000000c, 0x805c968, 0xb770cff4) = 0 free(0x0805b820) = <void> free(0x0805b838) = <void> free(0x0805b868) = <void> free(0x0805b850) = <void> free(0x0805b7f0) = <void> scandir(0x804f460, 0xbfc649bc, 0, 0x8049128, 0x805b85b <unfinished ...> alphasort(0x805b7f0, 0x805b7f4, 0, 0xb7711000, 0xb75d26d4) = -1 alphasort(0x805b7f8, 0x805b7fc, 0, 0xb7711000, 0xb75d26d4) = 1 alphasort(0x805b7f0, 0x805b7f8, 0, 1, 0xbfc6386c) = -1 alphasort(0x805b7f4, 0x805b7f8, 0, 1, 0xbfc6386c) = -1 <... scandir resumed> ) = 4 strcmp("2f", "2f") = 0 strcmp("31", "2f") = 1 strcmp("31", "31") = 0 free(0x0805b820) = <void> free(0x0805b838) = <void> free(0x0805b868) = <void> free(0x0805b850) = <void> free(0x0805b7f0) = <void> read(10, "", 140) = 140 nfs4_name_to_uid(0xbfc64946, 0xbfc6491c, 0, 0x804938c, 10) = 0 write(10, "", 140) = 140 event_add(0x805c910, 0, 0xbfc64944, 140, 0x6e656973) = 0 read(10, "\001\001r...@audible.transient.net", 140) = 140 nfs4_name_to_gid(0xbfc64946, 0xbfc64918, 0, 0x804938c, 10) = 0 write(10, "\001\001r...@audible.transient.net", 140) = 140 event_add(0x805c910, 0, 0xbfc64944, 140, 0x6e656973) = 0 read(10, "", 140) = 140 nfs4_name_to_uid(0xbfc64946, 0xbfc6491c, 0, 0x804938c, 10 <unfinished ...> vsyslog(4, 0xb77311fc, 0xbfc64804, 0xb76ed982, 0) = 115184 fprintf(0xb770d560, "%s: ", "rpc.idmapd") = 12 vfprintf(0xb770d560, "nss_getpwnam: name '%s' not foun"..., 0xbfc64804) = 71 fputc('\n', 0xb770d560) = 10 <... nfs4_name_to_uid resumed> ) = -2 write(10, "", 140) = 140 event_add(0x805c910, 0, 0xbfc64944, 140, 0x6e656973) = 0 read(10, "\001\001mu...@audible.transient.net", 140) = 140 nfs4_name_to_gid(0xbfc64946, 0xbfc64918, 0, 0x804938c, 10) = 0 write(10, "\001\001mu...@audible.transient.net", 140) = 140 event_add(0x805c910, 0, 0xbfc64944, 140, 0x6e656973) = 0 So you can see how things should work... the call to nfs4_name_to_uid that fails becuase I don't have that user on this client, and the following call to nfs4_name_to_gid that succeeds. Now I've got the most simple nsswitch you can have really... just "files" for password and group databases, and no caching layer at all. As you're using ldap, I'd expect your strace output to be more exciting. And if you're using a caching layer like nscd I'd definately try disabling it to see if that changes things at all. If nothing else this should help isolate how far the requests are getting before they fail. Obviously your LDAP server logs should show the lookups occuring, and as they don't, that's certainly suspicious. > > Were your kernels built with CONFIG_NFS_USE_NEW_IDMAPPER=y > > It is the standard kernel of squeeze (2.6.32-5-amd64) and according to > the config file this option does not exist. OK that's fine then. -- Jamie Heilman http://audible.transient.net/~jamie/ "Most people wouldn't know music if it came up and bit them on the ass." -Frank Zappa -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org