Long delays caused by rpcinfo

[David Parker]

Hello,

I recently set up a VM running Debian Wheezy (amd64) to be used as an NFS
server. I noticed that running "/etc/init.d/nfs-kernel-server start" would
hang for about 60 seconds while starting nfsd, but if I started nfsd
directly, there was no problem. After a lot of strace adventures and
Google searches, I eventually traced the problem to the "rpcinfo" command.
I commented out the following lines from the nfs-kernel-server init
script, everything started working:

$PREFIX/bin/rpcinfo -u localhost nfs 3 >/dev/null 2>&1 ||
RPCMOUNTDOPTS="$RPCMOUNTDOPTS --no-nfs-version 3"

Indeed, running "rpcinfo -u localhost nfs 3" causes a long pause before it
finally outputs the following:

rpcinfo: RPC: Port mapper failure - Timed out
program 100003 version 3 is not available

Running "rpcinfo -p localhost" causes the same long pause, and then outputs
this:

rpcinfo: can't contact portmapper: RPC: Remote system error -
Connection timed out

Running "showmount --exports" results in the long pause, and then outputs
this:

clnt_create: RPC: Port mapper failure - Timed out

However, running "rpcinfo -p" without specifying the host returns
immediately:

program vers proto port service
100000 4 tcp 111 portmapper
100000 3 tcp 111 portmapper
100000 2 tcp 111 portmapper
100000 4 udp 111 portmapper
100000 3 udp 111 portmapper
100000 2 udp 111 portmapper
100024 1 udp 42629 status
100024 1 tcp 56434 status

I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

Any idea why I would be seeing this behavior? Is there a configuration
option I'm missing? Any help would be greatly appreciated.

Thanks!
Dave

[Bob Proulx]

Post by David Parker
I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

AFAIK rpc.statd is not a portmapper replacement. The two portmapper
equivalents that I am aware of are:

portmap - RPC port mapper
rpcbind - converts RPC program numbers into universal addresses

The 'portmap' package is the older one. I think in newer releases it
has been replaced with 'rpcbind'. I don't know what is different
between them.

Try installing rpcbind. I think that will solve your problem.

Bob

[David Parker]

Thanks for the reply. Unfortunately, it looks like rpcbind is not the
culprit. I verified that rpcbind installed and running:

***@test-vm-1:~# ps -ef | grep bind
root 1538 1 0 11:23 ? 00:00:00 /sbin/rpcbind -w
root 28002 2289 0 15:17 pts/0 00:00:00 grep bind

I restarted the rpcbind service just to make sure...

***@test-vm-1:~# service rpcbind stop
[ ok ] Stopping rpcbind daemon....
***@test-vm-1:~# ps -ef | grep bind
root 28227 2289 0 15:18 pts/0 00:00:00 grep bind
***@test-vm-1:~# service rpcbind start
[ ok ] Starting rpcbind daemon....
***@test-vm-1:~# ps -ef | grep bind
root 28254 1 0 15:18 ? 00:00:00 /sbin/rpcbind -w
root 28288 2289 0 15:18 pts/0 00:00:00 grep bind

... but the problem persisted:

***@test-vm-1:~# rpcinfo -p localhost
<LONG PAUSE>
rpcinfo: can't contact portmapper: RPC: Remote system error - Connection
timed out

Anything else I can look into? FWIW, an strace shows that rpcbind gets
stuck when trying to connect to a socket on the loopback interface. The
relevant portion of the strace output is below:

socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
getsockname(3, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("0.0.0.0")}, [16]) = 0
bind(3, {sa_family=AF_INET, sin_port=htons(944),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
getsockname(3, {sa_family=AF_INET, sin_port=htons(944),
sin_addr=inet_addr("0.0.0.0")}, [16]) = 0
getsockopt(3, SOL_SOCKET, SO_TYPE, [1], [4]) = 0
setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=4*1024}) = 0
mmap(NULL, 200704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0x7fdfa4cfb000
getpeername(3, 0x7fff62295d00, [128]) = -1 ENOTCONN (Transport endpoint
is not connected)
connect(3, {sa_family=AF_INET, sin_port=htons(111),
sin_addr=inet_addr("127.0.0.1")}, 16) = -1 ETIMEDOUT (Connection timed out)
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
close(3) = 0
write(2, "rpcinfo: can't contact portmappe"..., 83rpcinfo: can't contact
portmapper: RPC: Remote system error - Connection timed out
) = 83
exit_group(1)

The long pause happens after this call:

connect(3, {sa_family=AF_INET, sin_port=htons(111),
sin_addr=inet_addr("127.0.0.1")}, 16)

Which eventually results in "= -1 ETIMEDOUT (Connection timed out)" and
moves on.

As always, any help will be greatly appreciated!

- Dave

Post by Bob Proulx

Post by David Parker
I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

AFAIK rpc.statd is not a portmapper replacement. The two portmapper
portmap - RPC port mapper
rpcbind - converts RPC program numbers into universal addresses
The 'portmap' package is the older one. I think in newer releases it
has been replaced with 'rpcbind'. I don't know what is different
between them.
Try installing rpcbind. I think that will solve your problem.
Bob

[Mark Neyhart]

Post by David Parker
Thanks for the reply. Unfortunately, it looks like rpcbind is not the
Anything else I can look into? FWIW, an strace shows that rpcbind gets
stuck when trying to connect to a socket on the loopback interface. The

Maybe rpcbind is not listening on the loopback interface.

What are the contents of /etc/hosts, /etc/hosts.deny and /etc/hosts.allow?

Mark

[David Parker]

***@test-vm-1:~# cat /etc/hosts
127.0.0.1 localhost localhost
192.168.25.200 testbed.utica.edu testbed
192.168.25.201 test-vm-1.utica.edu test-vm-1
192.168.25.202 test-vm-2.utica.edu test-vm-2
192.168.25.203 test-vm-3.utica.edu test-vm-3
192.168.25.204 test-vm-4.utica.edu test-vm-4

/etc/hosts.allow and /etc/hosts.deny are the Debian-delivered versions;
they only contain comments, no actual rules.

Thanks,
Dave

Post by Mark Neyhart

Post by David Parker
Thanks for the reply. Unfortunately, it looks like rpcbind is not the
Anything else I can look into? FWIW, an strace shows that rpcbind gets
stuck when trying to connect to a socket on the loopback interface. The

Maybe rpcbind is not listening on the loopback interface.
What are the contents of /etc/hosts, /etc/hosts.deny and /etc/hosts.allow?
Mark
--
with a subject of "unsubscribe". Trouble? Contact

[Bob Proulx]

I missed asking the obvious question. Does the NFS server work? Are
you able to NFS mount it onto clients? Because this is the difference
between some runtime functionality problem and a boot time
functionality problem.

Post by David Parker
127.0.0.1 localhost localhost

That isn't wrong but it is unusual. The format for that file is:

IP_address canonical_hostname [aliases...]

And so by listing localhost twice in an identical string it is setting
it to both be the canonical name and an alias to it. But since the
string is identical it isn't needed to be an alias. Therefore that
second localhost field should be removed. It should read:

127.0.0.1 localhost

Of course that isn't really either a problem or related to your
current issue. But like any broken window it should be fixed.

Post by David Parker
192.168.25.200 testbed.utica.edu testbed
192.168.25.201 test-vm-1.utica.edu test-vm-1
192.168.25.202 test-vm-2.utica.edu test-vm-2
192.168.25.203 test-vm-3.utica.edu test-vm-3
192.168.25.204 test-vm-4.utica.edu test-vm-4

One of those is the IP address of the NFS server itself?

How are you configuring the network? In /etc/network/interfaces I
assume that for the NFS server you are setting up a static IP
address. Or at least I think you should if you are not.

Example:

auto eth0
iface eth0 inet static
address 192.168.25.200
netmask 255.255.255.0
gateway 192.168.25.1

Use "auto" here rather than "allow-hotplug". Specifically I think
that may have some bearing on your problem. With "allow-hotplug" the
system runs in the newer event driven mode capable of using hotplug
devices. That should work and if it doesn't it would be good to track
down why and fix it. The "auto" setting runs by the boot time init.d
scripts. Here is a documentation pointer.

http://www.debian.org/doc/manuals/debian-reference/ch05.en.html#_the_basic_syntax_of_etc_network_interfaces

I know that NIS has some issues with the event driven route but works
perfectly with the boot time route. Perhaps this is related to your
problem too. Try "auto" and see if that makes a difference.

Bob

[Mark Neyhart]

Post by David Parker
127.0.0.1 localhost localhost
192.168.25.200 testbed.utica.edu testbed
192.168.25.201 test-vm-1.utica.edu test-vm-1
192.168.25.202 test-vm-2.utica.edu test-vm-2
192.168.25.203 test-vm-3.utica.edu test-vm-3
192.168.25.204 test-vm-4.utica.edu test-vm-4
/etc/hosts.allow and /etc/hosts.deny are the Debian-delivered versions;
they only contain comments, no actual rules.

I don't see anything broken here.

Does "rpcinfo -p 127.0.0.1" work?

Does /var/log/daemon.log have any entries at the time when
"rpcinfo -p localhost" is run?

Mark

[Tom H]

Post by Bob Proulx

Post by David Parker
I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

AFAIK rpc.statd is not a portmapper replacement. The two portmapper
portmap - RPC port mapper
rpcbind - converts RPC program numbers into universal addresses
The 'portmap' package is the older one. I think in newer releases it
has been replaced with 'rpcbind'. I don't know what is different
between them.

rpcbind uses ti-rpc rather than sunrpc and can handle nfsv4 and ipv6.

[David Parker]

Hello,

Thanks for the suggestions. The combination of checking
/etc/network/interfaces and verifying that rpcbind was listening on
127.0.0.1 led me in the right direction, and boy do I feel silly...

Somehow, my interfaces file was missing the loopback entry, so the loopback
interface showed in the "ifconfig" output but it wasn't actually up. I
added these lines:

auto lo
iface lo inet loopback

Then, after "ifup lo", everything just worked.

I think I wrote the interfaces file from scratch and copied it over the
original, and of course, I didn't include the loopback interface. *Sigh*.

Thanks again!

- Dave

Post by Tom H

Post by Bob Proulx

Post by David Parker
I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

AFAIK rpc.statd is not a portmapper replacement. The two portmapper
portmap - RPC port mapper
rpcbind - converts RPC program numbers into universal addresses
The 'portmap' package is the older one. I think in newer releases it
has been replaced with 'rpcbind'. I don't know what is different
between them.

rpcbind uses ti-rpc rather than sunrpc and can handle nfsv4 and ipv6.
--
with a subject of "unsubscribe". Trouble? Contact

[David Parker]

And for the sake of completeness, yes, NFS clients were able to mount the
exported volume on this server once the nfs-kernel-server startup
completed. And that makes a lot of sense to me now, because the entire
issue was in rpcbind's attempt to verify that it could connect to
127.0.0.1, which doesn't matter for remote mounts.

Post by David Parker
Hello,
Thanks for the suggestions. The combination of checking
/etc/network/interfaces and verifying that rpcbind was listening on
127.0.0.1 led me in the right direction, and boy do I feel silly...
Somehow, my interfaces file was missing the loopback entry, so the
loopback interface showed in the "ifconfig" output but it wasn't actually
auto lo
iface lo inet loopback
Then, after "ifup lo", everything just worked.
I think I wrote the interfaces file from scratch and copied it over the
original, and of course, I didn't include the loopback interface. *Sigh*.
Thanks again!
- Dave

Post by Tom H

Post by Bob Proulx

Post by David Parker
I have confirmed that rpc.statd is running, which I believe is the port
mapper in newer distributions.

AFAIK rpc.statd is not a portmapper replacement. The two portmapper
portmap - RPC port mapper
rpcbind - converts RPC program numbers into universal addresses
The 'portmap' package is the older one. I think in newer releases it
has been replaced with 'rpcbind'. I don't know what is different
between them.

rpcbind uses ti-rpc rather than sunrpc and can handle nfsv4 and ipv6.
--
with a subject of "unsubscribe". Trouble? Contact

--
Dave Parker
Systems Administrator
Utica College
Integrated Information Technology Services
[phone]
Registered Linux User #408177