Hi,
On Mon, Jul 10, 2023 at 04:33:24PM +0800, Ian Kent wrote:
>
> On 10/7/23 14:24, Salvatore Bonaccorso wrote:
> > Hi Ian,
> >
> > On Mon, Jul 10, 2023 at 10:05:12AM +0800, Ian Kent wrote:
> > > On 9/7/23 22:57, Salvatore Bonaccorso wrote:
> > > > Hi
> > > >
> > > > The following sort of regression was noticed while updating a client
> > > > running Debian buster (with autofs 5.1.2 based) to Debian bullseye
> > > > (5.1.7 based autofs), but verified it's still present with 5.1.8. The
> > > > folloing setup is present:
> > > >
> > > > There is a NFS server, dualstacked, with both public IPv4 and IPv6
> > > > addresses resolvable in DNS. As I cannot put the public IPs here in
> > > > the report, let's assume It is called nfs-server with addresses
> > > > 192.168.122.188 and fc00:192:168:122::188.
> > > >
> > > > The client initially running Debian buster, is not dualstacked, has
> > > > only IPv4 and has correct routing, e.g. pinging to nfs-server will as
> > > > well go to the IPv4 address of nfs-server, or any tcp connection will
> > > > go to IPv4 (e.g. ssh -vvv nfs-server).
> > > >
> > > > Automount configuration is fairly simple:
> > > >
> > > > auto.master:
> > > > [...]
> > > > /home /etc/auto/homes01
> > > > [...]
> > > >
> > > > and /etc/auto/homes01
> > > > [...]
> > > > * nfs-server:/srv/homes/homes01/&
> > > > [...]
> > > >
> > > > (note in fact the real configuration is slightly more complex,
> > > > nosuid,rw,hard,proto=tcp as options, but veried as wel stripping down the
> > > > options, even dropping proto=tcp). I hope I correctly de-anonymized
> > > > not messing up with paths in the logs below.
> > > >
> > > > After the update to autofs 5.1.7 based version there is a 10s delay on
> > > > mounts from the servers.
> > > >
> > > > In the following logs I had to slightly deanonymize the names. But I
> > > > think the delay problem is seen enough by the timestamps.
> > > >
> > > > Before the update, with autofs 5.1.2:
> > > >
> > > > Jul 09 11:54:41 clienthost automount[5143]: handle_packet: type = 3
> > > > Jul 09 11:54:41 clienthost automount[5143]: handle_packet_missing_indirect: token 26, name username, request pid 5285
> > > > Jul 09 11:54:41 clienthost automount[5143]: attempting to mount entry /home/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: lookup_mount: lookup(program): username -> -nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: parse_mount: parse(sun): expanded entry: -nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: parse_mount: parse(sun): gathered options: nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:54:41 clienthost automount[5143]: parse_mount: parse(sun): dequote("nfs-server:/srv/homes/homes01/username") -> nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: parse_mount: parse(sun): core of entry: options=nosuid,rw,hard,proto=tcp, loc=nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: sun_mount: parse(sun): mounting root /home, mountpoint username, what nfs-server:/srv/homes/homes01/username, fstype nfs, options nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:54:41 clienthost automount[5143]: mount_mount: mount(nfs): root=/home name=username what=nfs-server:/srv/homes/homes01/username, fstype=nfs, options=nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:54:41 clienthost automount[5143]: mount_mount: mount(nfs): nfs options="nosuid,rw,hard,proto=tcp", nobind=0, nosymlink=0, ro=0
> > > > Jul 09 11:54:41 clienthost automount[5143]: get_nfs_info: called with host nfs-server(192.168.122.188) proto 6 version 0x30
> > > > Jul 09 11:54:41 clienthost automount[5143]: get_nfs_info: nfs v3 rpc ping time: 0.000000
> > > > Jul 09 11:54:41 clienthost automount[5143]: get_nfs_info: host nfs-server cost 0 weight 0
> > > > Jul 09 11:54:41 clienthost automount[5143]: prune_host_list: selected subset of hosts that support NFS3 over TCP
> > > > Jul 09 11:54:41 clienthost automount[5143]: mount_mount: mount(nfs): calling mkdir_path /home/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: mount_mount: mount(nfs): calling mount -t nfs -s -o nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username /home/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: mount_mount: mount(nfs): mounted nfs-server:/srv/homes/homes01/username on /home/username
> > > > Jul 09 11:54:41 clienthost automount[5143]: dev_ioctl_send_ready: token = 26
> > > > Jul 09 11:54:41 clienthost automount[5143]: mounted /home/username
> > > >
> > > > After the update to 5.1.7 (or 5.1.8):
> > > >
> > > > Jul 09 11:56:23 clienthost automount[6952]: handle_packet: type = 3
> > > > Jul 09 11:56:23 clienthost automount[6952]: handle_packet_missing_indirect: token 33, name username, request pid 7104
> > > > Jul 09 11:56:23 clienthost automount[6952]: attempting to mount entry /home/username
> > > > Jul 09 11:56:23 clienthost automount[6952]: lookup_mount: lookup(program): username -> -nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:56:23 clienthost automount[6952]: parse_mount: parse(sun): expanded entry: -nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:56:23 clienthost automount[6952]: parse_mount: parse(sun): gathered options: nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:56:23 clienthost automount[6952]: parse_mount: parse(sun): dequote("nfs-server:/srv/homes/homes01/username") -> nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:56:23 clienthost automount[6952]: parse_mount: parse(sun): core of entry: options=nosuid,rw,hard,proto=tcp, loc=nfs-server:/srv/homes/homes01/username
> > > > Jul 09 11:56:23 clienthost automount[6952]: sun_mount: parse(sun): mounting root /home, mountpoint username, what nfs-server:/srv/homes/homes01/username, fstype nfs, options nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:56:23 clienthost automount[6952]: mount(nfs): root=/home name=username what=nfs-server:/srv/homes/homes01/username, fstype=nfs, options=nosuid,rw,hard,proto=tcp
> > > > Jul 09 11:56:23 clienthost automount[6952]: mount(nfs): nfs options="nosuid,rw,hard,proto=tcp", nobind=0, nosymlink=0, ro=0
> > > > Jul 09 11:56:23 clienthost automount[6952]: get_nfs_info: called with host nfs-server(192.168.122.188) proto 6 version 0x20
> > > > Jul 09 11:56:23 clienthost automount[6952]: get_nfs_info: nfs v3 rpc ping time: 0.000184
> > > > Jul 09 11:56:23 clienthost automount[6952]: get_nfs_info: host nfs-server cost 183 weight 0
> > > > Jul 09 11:56:23 clienthost automount[6952]: prune_host_list: selected subset of hosts that support NFS3 over TCP
> > > > Jul 09 11:56:23 clienthost automount[6952]: get_supported_ver_and_cost: called with host nfs-server(fc00:192:168:122::188) version 0x20
> > > > Jul 09 11:56:33 clienthost automount[6952]: get_supported_ver_and_cost: rpc ping time 0.000352
> > > > Jul 09 11:56:33 clienthost automount[6952]: get_supported_ver_and_cost: cost 352 weight 0
> > > > Jul 09 11:56:33 clienthost automount[6952]: mount_mount: mount(nfs): calling mkdir_path /home/username
> > > > Jul 09 11:56:33 clienthost automount[6952]: mount(nfs): calling mount -t nfs -s -o nosuid,rw,hard,proto=tcp nfs-server:/srv/homes/homes01/username /home/username
> > > > Jul 09 11:56:33 clienthost automount[6952]: mount_mount: mount(nfs): mounted nfs-server:/srv/homes/homes01/username on /home/username
> > > > Jul 09 11:56:33 clienthost automount[6952]: dev_ioctl_send_ready: token = 33
> > > > Jul 09 11:56:33 clienthost automount[6952]: mounted /home/username
> > > >
> > > > while first get_nfs_info is called again with host
> > > > nfs-server(192.168.12.2188), there is a get_supported_ver_and_cost
> > > > with the IPv6 address, hanging for 10s.
> > > The later call timed out, it's timeout is 10 seconds for addresses
> > >
> > > that look like they are on the local network so the IPv6 address is
> > >
> > > not responding.
> > >
> > >
> > > I know that 10 seconds is a bit long for interactive use, perhaps
> > >
> > > it should be a bit less, but it's better than the 2 minutes we
> > >
> > > would often see ...
> > Yes fully understand. We got complaints from clients having to wait
> > 10s for their homes to be mounted, this is how we start investigating
> > it.
> >
> > > I guess you are saying it should be responding ... not sure what
> > >
> > > I can do about that, I will need to reproduce the problem and IPv6
> > >
> > > is still not something I have a setup for easily available.
> > I'm not sure. I was actually surprised, given the Client is IPv4 only
> > networking, that there was happing with the updated autofs actually
> > a call to the IPv6 address.
> >
> > > > If I just revert c578e5b37c3c ("autofs-5.1.5 - Fix NFS mount from IPv6
> > > > addresses") then the mount is again quick, but logs an additional
> > > >
> > > > Jul 09 16:31:34 clienthost automount[12045]: check_address_proto: requested protocol does not match address
> > > >
> > > > so likely not the right fix.
> > > That does raise some interesting alternatives though.
> > >
> > > I'm not sure what the function check_address_proto() is seeing but it
> > >
> > > essentially (in 5.1.8) says "if the rpc request is for IPv6 and the
> > >
> > > host address length is not set to the length of an IPv6 address bail
> > >
> > > out". So whatever is wrong there is probably still wrong just not
> > >
> > > happening due to the check returning a fail.
> > >
> > >
> > > If I can setup an environment I can check that out further but sounds
> > >
> > > a bit suspicious. I can of course check the code to see if there's an
> > >
> > > obvious setup mistake ...
> > If I can provide any help in debugging this or you can give me hints
> > what I can try let me know. I will need to release the client host
> > soonish again to the customers, but will try to make a similar test
> > client available for further testing.
> >
> > > > I suspect mounts from server, which are dualstacked, but route to them
> > > > is only IPv4, are not correctly handled after 90532146bc0e
> > > > ("autofs-5.1.3 - fix ipv6 proto option handling") and c578e5b37c3c
> > > > ("autofs-5.1.5 - Fix NFS mount from IPv6 addresses").
> > > I'm not sure that these changes affect the routing at all, at least
> > >
> > > not due to autofs itself and the above is a proto TCP request so it
> > >
> > > shouldn't be the server simply not responding ... not sure why it's
> > >
> > > happening.
> > >
> > >
> > > The difference between the first and second log traces looks like
> > >
> > > dns lookup has returned two hosts in the second availability ping,
> > >
> > > an IPv4 and an IPv6 address. Not sure why an IPv6 address isn't
> > >
> > > present in the first availability ping.
> > >
> > >
> > > It might also be that NFSv3 is being checked for availability rather
> > >
> > > than IPv4. I've assumed that NFS v3 works over IPv6 ...
> > About NFsv3: This is actually independent, it is the same if I use
> > NFSv4 (with -vers=4 option, which we have in the original setup, I
> > just tried to strip down as many options as possible for the
> > reproducing case, though still not minimal, but we can actually ommint
> > any of the options).
> >
> > > > (note the package in Debian *is* built with --with-libtirpc).
> > > >
> > > > Does any of the above make sense?
> > > Sadly it does make sense but, as I say, I don't know what's causing
> > >
> > > it.
> > Ok. Again I'm eager to help as much as possible to pinpoint the issue,
> > but might need some hints what I should/can try to isolate the
> > problem. Are there potential missconficuration on client side which
> > cause us problem for autofs in this setup?
>
> This sounds a bit strange because above you mentioned the environment
>
> is IPv4 so the curious thing is where is that IPv6 address even coming
>
> from. Those addresses are coming from glibc so it's DNS or a hosts file.
The environment is equipped to be able to do dual stack, and in fact
the nfs-server has both IPv4 and IPv6.
The particular client is though only equipped with IPv4 address.
For the nfs-server both IPv4 and IPv6 addresses are both in DNS and as
well locally on every hosts in /etc/hosts file deployed via
configuration managment.
So both resolvable even from the client, but the client reaches the
server only via IPv4.
Regards,
Salvatore
