Bug#644948: nfs-common: Wrong uid/gid with latest version using NFSv4
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\1root@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\1root@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\1root@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\1root@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\1music@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\1music@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\1music@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\1music@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\001root@audible.transient.net", 140) = 140
nfs4_name_to_gid(0xbfc64946, 0xbfc64918, 0, 0x804938c, 10) = 0
write(10, "\001\001root@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\001music@audible.transient.net", 140) = 140
nfs4_name_to_gid(0xbfc64946, 0xbfc64918, 0, 0x804938c, 10) = 0
write(10, "\001\001music@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
Reply to: