Description of problem: This is pretty much a rehash of bug #1029611. If I use /net -hosts, my automounts do not work. Switching to /net /etc/auto.net works. With -hosts, I get: ----------------- Dec 05 11:49:33 <client> automount[11187]: get_exports: lookup(hosts): exports lookup failed for <server> Dec 05 11:49:33 <client> automount[11187]: key "<server>" not found in map source(s). ----------------- Both client and server are in DNS. Version-Release number of selected component (if applicable): autofs-5.0.7-35.fc20.x86_64 How reproducible: Always. Steps to Reproduce: 1. Try ls /net/<server>. 2. Long delay, fail. Actual results: Fails to find host and auto mount does not work. Expected results: Worked in F-19. Additional info:
(In reply to Bojan Smojver from comment #0) > Description of problem: > This is pretty much a rehash of bug #1029611. If I use /net -hosts, my > automounts do not work. Switching to /net /etc/auto.net works. With -hosts, > I get: > ----------------- > Dec 05 11:49:33 <client> automount[11187]: get_exports: lookup(hosts): > exports lookup failed for <server> > Dec 05 11:49:33 <client> automount[11187]: key "<server>" not found in map > source(s). > ----------------- > > Both client and server are in DNS. > > Version-Release number of selected component (if applicable): > autofs-5.0.7-35.fc20.x86_64 Agggh ... I see the problem. A recent change that assumes a prior change to configure is present. It's present in the upstream source but cherry picking of the change causes configure to fail. Saw this same problem recently in RHEL-7, I'll fix it. Ian
autofs-5.0.7-37.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/autofs-5.0.7-37.fc20
Package autofs-5.0.7-37.fc20: * should fix your issue, * was pushed to the Fedora 20 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing autofs-5.0.7-37.fc20' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2013-22806/autofs-5.0.7-37.fc20 then log in and leave karma (feedback).
autofs-5.0.7-37.fc20 has been pushed to the Fedora 20 stable repository. If problems still persist, please make note of it in this bug report.
Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded from F19 yesterday and seeing the same issue. Workaround (switch /net -hosts -> /net /etc/auto.net) still functional.
(In reply to Kevin Gardner from comment #5) > Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded > from F19 yesterday and seeing the same issue. Workaround (switch /net > -hosts -> /net /etc/auto.net) still functional. Can you provide a full debug log please.
(In reply to Ian Kent from comment #6) > (In reply to Kevin Gardner from comment #5) > > Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded > > from F19 yesterday and seeing the same issue. Workaround (switch /net > > -hosts -> /net /etc/auto.net) still functional. > > Can you provide a full debug log please. Glad to. I'd appreciate a pointer or two re: which logs you'd like (and how they're triggered, if not extracts from routine /var/log entries) to ensure that I can get you the most useful information most quickly. Thanks ---
(In reply to Kevin Gardner from comment #7) > (In reply to Ian Kent from comment #6) > > (In reply to Kevin Gardner from comment #5) > > > Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded > > > from F19 yesterday and seeing the same issue. Workaround (switch /net > > > -hosts -> /net /etc/auto.net) still functional. > > > > Can you provide a full debug log please. > > Glad to. I'd appreciate a pointer or two re: which logs you'd like (and how > they're triggered, if not extracts from routine /var/log entries) to ensure > that I can get you the most useful information most quickly. Thanks --- Umm ... you need to ensure that the facility daemon is recording log level debug and above. I usually do that with: daemon.* /var/log/debug.log in the syslog (or rsyslog) configuration. Then you need to tell autofs to log debug output by setting the config entry LOGGING="debug" in /etc/sysconfig/autofs.
Thanks, Ian - pointers much appreciated. I've followed as you suggested and have captured debugging info which I've pasted in below. The log is broken into two parts, both of which document chandra attempting to mount ares:/usr2; an initial attempt is made with /net -hosts in /etc/auto.master which is unsuccessful, while a subsequent attempt with /net /etc/auto.net works fine. Holler if I can provide more info. Thanks, Kevin (In reply to Ian Kent from comment #8) > (In reply to Kevin Gardner from comment #7) > > (In reply to Ian Kent from comment #6) > > > (In reply to Kevin Gardner from comment #5) > > > > Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded > > > > from F19 yesterday and seeing the same issue. Workaround (switch /net > > > > -hosts -> /net /etc/auto.net) still functional. > > > > > > Can you provide a full debug log please. > > > > Glad to. I'd appreciate a pointer or two re: which logs you'd like (and how > > they're triggered, if not extracts from routine /var/log entries) to ensure > > that I can get you the most useful information most quickly. Thanks --- > > Umm ... you need to ensure that the facility daemon is recording > log level debug and above. > > I usually do that with: > > daemon.* /var/log/debug.log > > in the syslog (or rsyslog) configuration. > > Then you need to tell autofs to log debug output by setting the config > entry LOGGING="debug" in /etc/sysconfig/autofs. ----- STOP AUTOFS, SWITCH TO /net -hosts, RESTART AND ATTEMPT TO MOUNT ares:/usr2 Dec 21 08:02:11 chandra systemd: Starting Automounts filesystems on demand... Dec 21 08:02:11 chandra automount[10204]: Starting automounter version 5.0.7-37.fc20, master map auto.master Dec 21 08:02:11 chandra automount[10204]: using kernel protocol version 5.02 Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_master: reading master files auto.master Dec 21 08:02:11 chandra automount[10204]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:02:11 chandra automount[10204]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:02:11 chandra automount[10204]: spawn_umount: mtab link detected, passing -n to mount Dec 21 08:02:11 chandra automount[10204]: lookup_read_master: lookup(file): read entry /misc Dec 21 08:02:11 chandra automount[10204]: lookup_read_master: lookup(file): read entry /net Dec 21 08:02:11 chandra automount[10204]: lookup_read_master: lookup(file): read entry +dir:/etc/auto.master.d Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_master: reading master dir /etc/auto.master.d Dec 21 08:02:11 chandra automount[10204]: lookup_read_master: lookup(dir): scandir: /etc/auto.master.d Dec 21 08:02:11 chandra automount[10204]: lookup_read_master: lookup(file): read entry +auto.master Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_master: reading master files auto.master Dec 21 08:02:11 chandra automount[10204]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_master: reading master nis auto.master Dec 21 08:02:11 chandra automount[10204]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:02:11 chandra automount[10204]: lookup(yp): read of master map auto.master failed: No such map in server's domain Dec 21 08:02:11 chandra automount[10204]: lookup(file): failed to read included master map auto.master Dec 21 08:02:11 chandra automount[10204]: master_do_mount: mounting /misc Dec 21 08:02:11 chandra automount[10204]: automount_path_to_fifo: fifo name /run/autofs.fifo-misc Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_map: reading map file /etc/auto.misc Dec 21 08:02:11 chandra automount[10204]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:02:11 chandra automount[10204]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:02:11 chandra automount[10204]: spawn_umount: mtab link detected, passing -n to mount Dec 21 08:02:11 chandra automount[10204]: mounted indirect on /misc with timeout 300, freq 75 seconds Dec 21 08:02:11 chandra automount[10204]: st_ready: st_ready(): state = 0 path /misc Dec 21 08:02:11 chandra automount[10204]: master_do_mount: mounting /net Dec 21 08:02:11 chandra automount[10204]: automount_path_to_fifo: fifo name /run/autofs.fifo-net Dec 21 08:02:11 chandra automount[10204]: lookup_nss_read_map: reading map hosts (null) Dec 21 08:02:11 chandra automount[10204]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:02:11 chandra automount[10204]: lookup_read_map: lookup(hosts): read hosts map Dec 21 08:02:11 chandra automount[10204]: lookup_read_map: lookup(hosts): map not browsable, update existing host entries only Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: trying to re-connect to mount /net Dec 21 08:02:11 chandra automount[10204]: mounted indirect on /net with timeout 300, freq 75 seconds Dec 21 08:02:11 chandra automount[10204]: lookup_mount: lookup(hosts): chandra -> (null) Dec 21 08:02:11 chandra automount[10204]: get_exports: lookup(hosts): fetchng export list for chandra Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): expanded entry: "/usr/local" "chandra:/usr/local" "/usr2" "chandra:/usr2" Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): gathered options: Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): dequote(""/usr/local"") -> /usr/local Dec 21 08:02:11 chandra automount[10204]: parse_mapent: parse(sun): gathered options: Dec 21 08:02:11 chandra automount[10204]: parse_mapent: parse(sun): dequote(""chandra:/usr/local"") -> chandra:/usr/local Dec 21 08:02:11 chandra automount[10204]: update_offset_entry: parse(sun): updated multi-mount offset /usr/local -> chandra:/usr/local Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): dequote(""/usr2"") -> /usr2 Dec 21 08:02:11 chandra automount[10204]: parse_mapent: parse(sun): gathered options: Dec 21 08:02:11 chandra automount[10204]: parse_mapent: parse(sun): dequote(""chandra:/usr2"") -> chandra:/usr2 Dec 21 08:02:11 chandra automount[10204]: update_offset_entry: parse(sun): updated multi-mount offset /usr2 -> chandra:/usr2 Dec 21 08:02:11 chandra automount[10204]: do_mount_autofs_offset: mount offset /net/chandra/usr/local at /net/chandra Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: trying to re-connect to mount /net/chandra/usr/local Dec 21 08:02:11 chandra automount[10204]: mounted offset on /net/chandra/usr/local with timeout 300, freq 75 seconds Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: re-connected to mount /net/chandra/usr/local Dec 21 08:02:11 chandra automount[10204]: do_mount_autofs_offset: mount offset /net/chandra/usr2 at /net/chandra Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: trying to re-connect to mount /net/chandra/usr2 Dec 21 08:02:11 chandra automount[10204]: mounted offset on /net/chandra/usr2 with timeout 300, freq 75 seconds Dec 21 08:02:11 chandra automount[10204]: lookup_mount: lookup(hosts): /net/chandra/usr2 -> chandra:/usr2 Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): expanded entry: chandra:/usr2 Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): gathered options: Dec 21 08:02:11 chandra automount[10204]: sun_mount: parse(sun): mounting root /net/chandra/usr2, mountpoint /net/chandra/usr2, what chandra:/usr2, fstype nfs, options nosuid,nodev,intr Dec 21 08:02:11 chandra automount[10204]: re-connected to /net/chandra/usr2 Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: re-connected to mount /net/chandra/usr2 Dec 21 08:02:11 chandra automount[10204]: re-connected to /net/chandra Dec 21 08:02:12 chandra automount[10204]: remount_active_mount: re-connected to mount /net Dec 21 08:02:12 chandra automount[10204]: st_ready: st_ready(): state = 0 path /net ----- STOP AUTOFS, SWITCH TO /net /etc/auto.net, RESTART AND TRY AGAIN Dec 21 08:02:12 chandra systemd: Started Automounts filesystems on demand. Dec 21 08:02:28 chandra automount[10204]: handle_packet: type = 3 Dec 21 08:02:28 chandra automount[10204]: handle_packet_missing_indirect: token 654, name ares, request pid 9428 Dec 21 08:02:28 chandra automount[10204]: attempting to mount entry /net/ares Dec 21 08:02:28 chandra automount[10204]: lookup_mount: lookup(hosts): ares -> (null) Dec 21 08:02:28 chandra automount[10204]: get_exports: lookup(hosts): fetchng export list for ares Dec 21 08:02:28 chandra automount[10204]: get_exports: lookup(hosts): exports lookup failed for ares Dec 21 08:02:28 chandra automount[10204]: key "ares" not found in map source(s). Dec 21 08:02:28 chandra automount[10204]: dev_ioctl_send_fail: token = 654 Dec 21 08:02:28 chandra automount[10204]: failed to mount /net/ares Dec 21 08:02:28 chandra automount[10204]: handle_packet: type = 3 Dec 21 08:02:28 chandra automount[10204]: handle_packet_missing_indirect: token 655, name ares, request pid 9428 Dec 21 08:02:28 chandra automount[10204]: dev_ioctl_send_fail: token = 655 Dec 21 08:02:28 chandra automount[10204]: handle_packet: type = 3 Dec 21 08:02:28 chandra automount[10204]: handle_packet_missing_indirect: token 656, name ares, request pid 9428 Dec 21 08:02:28 chandra automount[10204]: dev_ioctl_send_fail: token = 656 Dec 21 08:03:13 chandra systemd: Stopping Automounts filesystems on demand... Dec 21 08:03:13 chandra automount[10204]: do_notify_state: signal 15 Dec 21 08:03:13 chandra automount[10204]: master_notify_state_change: sig 15 switching /misc from 1 to 5 Dec 21 08:03:13 chandra automount[10204]: st_prepare_shutdown: state 1 path /misc Dec 21 08:03:13 chandra automount[10204]: expire_proc: exp_proc = 3044014912 path /misc Dec 21 08:03:13 chandra automount[10204]: master_notify_state_change: sig 15 switching /net from 1 to 5 Dec 21 08:03:13 chandra automount[10204]: st_prepare_shutdown: state 1 path /net Dec 21 08:03:13 chandra automount[10204]: expire_proc: exp_proc = 3042962240 path /net Dec 21 08:03:13 chandra automount[10204]: expire_cleanup: got thid 3044014912 path /misc stat 0 Dec 21 08:03:13 chandra automount[10204]: expire_cleanup: sigchld: exp 3044014912 finished, switching from 5 to 7 Dec 21 08:03:13 chandra automount[10204]: st_shutdown: state 5 path /misc Dec 21 08:03:13 chandra automount[10204]: expire_proc_indirect: expire /net/chandra/usr2 Dec 21 08:03:13 chandra automount[10204]: 1 remaining in /net Dec 21 08:03:13 chandra automount[10204]: expire_cleanup: got thid 3042962240 path /net stat 4 Dec 21 08:03:13 chandra automount[10204]: expire_cleanup: sigchld: exp 3042962240 finished, switching from 5 to 7 Dec 21 08:03:13 chandra automount[10204]: st_shutdown: state 5 path /net Dec 21 08:03:13 chandra automount[10204]: umount_multi: path /misc incl 0 Dec 21 08:03:13 chandra automount[10204]: umounted indirect mount /misc Dec 21 08:03:13 chandra automount[10204]: automount_path_to_fifo: fifo name /run/autofs.fifo-misc Dec 21 08:03:13 chandra automount[10204]: shut down path /misc Dec 21 08:03:13 chandra automount[10204]: umount_multi: path /net incl 0 Dec 21 08:03:13 chandra automount[10204]: rm_unwanted_fn: removing directory /net/chandra/usr Dec 21 08:03:13 chandra automount[10204]: unable to remove directory /net/chandra/usr: Directory not empty Dec 21 08:03:13 chandra automount[10204]: rm_unwanted_fn: removing directory /net/chandra Dec 21 08:03:13 chandra automount[10204]: unable to remove directory /net/chandra: Directory not empty Dec 21 08:03:13 chandra automount[10204]: umount_autofs_indirect: ask umount returned busy /net Dec 21 08:03:15 chandra automount[10204]: umount_autofs_indirect: mount point /net is in use Dec 21 08:03:15 chandra automount[10204]: automount_path_to_fifo: fifo name /run/autofs.fifo-net Dec 21 08:03:15 chandra automount[10204]: failed to remove dir /net: Device or resource busy Dec 21 08:03:15 chandra automount[10204]: shut down path /net Dec 21 08:03:15 chandra automount[10204]: autofs stopped Dec 21 08:03:15 chandra automount[10227]: Starting automounter version 5.0.7-37.fc20, master map auto.master Dec 21 08:03:15 chandra automount[10227]: using kernel protocol version 5.02 Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_master: reading master files auto.master Dec 21 08:03:15 chandra automount[10227]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:03:15 chandra automount[10227]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:03:15 chandra automount[10227]: spawn_umount: mtab link detected, passing -n to mount Dec 21 08:03:15 chandra automount[10227]: lookup_read_master: lookup(file): read entry /misc Dec 21 08:03:15 chandra automount[10227]: lookup_read_master: lookup(file): read entry /net Dec 21 08:03:15 chandra automount[10227]: lookup_read_master: lookup(file): read entry +dir:/etc/auto.master.d Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_master: reading master dir /etc/auto.master.d Dec 21 08:03:15 chandra automount[10227]: lookup_read_master: lookup(dir): scandir: /etc/auto.master.d Dec 21 08:03:15 chandra automount[10227]: lookup_read_master: lookup(file): read entry +auto.master Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_master: reading master files auto.master Dec 21 08:03:15 chandra automount[10227]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_master: reading master nis auto.master Dec 21 08:03:15 chandra automount[10227]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:03:15 chandra automount[10227]: lookup(yp): read of master map auto.master failed: No such map in server's domain Dec 21 08:03:15 chandra automount[10227]: lookup(file): failed to read included master map auto.master Dec 21 08:03:15 chandra automount[10227]: master_do_mount: mounting /misc Dec 21 08:03:15 chandra automount[10227]: automount_path_to_fifo: fifo name /run/autofs.fifo-misc Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_map: reading map file /etc/auto.misc Dec 21 08:03:15 chandra automount[10227]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:03:15 chandra automount[10227]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:03:15 chandra automount[10227]: spawn_umount: mtab link detected, passing -n to mount Dec 21 08:03:15 chandra automount[10227]: mounted indirect on /misc with timeout 300, freq 75 seconds Dec 21 08:03:15 chandra automount[10227]: st_ready: st_ready(): state = 0 path /misc Dec 21 08:03:15 chandra automount[10227]: master_do_mount: mounting /net Dec 21 08:03:15 chandra automount[10227]: automount_path_to_fifo: fifo name /run/autofs.fifo-net Dec 21 08:03:15 chandra automount[10227]: lookup_nss_read_map: reading map file /etc/auto.net Dec 21 08:03:15 chandra automount[10227]: parse_init: parse(sun): init gathered global options: (null) Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: trying to re-connect to mount /net Dec 21 08:03:15 chandra automount[10227]: mounted indirect on /net with timeout 300, freq 75 seconds Dec 21 08:03:15 chandra automount[10227]: lookup_mount: lookup(program): looking up chandra Dec 21 08:03:15 chandra systemd: Starting Automounts filesystems on demand... Dec 21 08:03:15 chandra automount[10227]: lookup_mount: lookup(program): chandra -> -fstype=nfs,hard,intr,nodev,nosuid /usr/local chandra:/usr/local /usr2 chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid /usr/local chandra:/usr/local /usr2 chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): dequote("/usr/local") -> /usr/local Dec 21 08:03:15 chandra automount[10227]: parse_mapent: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:15 chandra automount[10227]: parse_mapent: parse(sun): dequote("chandra:/usr/local") -> chandra:/usr/local Dec 21 08:03:15 chandra automount[10227]: update_offset_entry: parse(sun): updated multi-mount offset /usr/local -> -fstype=nfs,hard,intr,nodev,nosuid chandra:/usr/local Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): dequote("/usr2") -> /usr2 Dec 21 08:03:15 chandra automount[10227]: parse_mapent: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:15 chandra automount[10227]: parse_mapent: parse(sun): dequote("chandra:/usr2") -> chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: update_offset_entry: parse(sun): updated multi-mount offset /usr2 -> -fstype=nfs,hard,intr,nodev,nosuid chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: do_mount_autofs_offset: mount offset /net/chandra/usr/local at /net/chandra Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: trying to re-connect to mount /net/chandra/usr/local Dec 21 08:03:15 chandra automount[10227]: mounted offset on /net/chandra/usr/local with timeout 300, freq 75 seconds Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: re-connected to mount /net/chandra/usr/local Dec 21 08:03:15 chandra automount[10227]: do_mount_autofs_offset: mount offset /net/chandra/usr2 at /net/chandra Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: trying to re-connect to mount /net/chandra/usr2 Dec 21 08:03:15 chandra automount[10227]: mounted offset on /net/chandra/usr2 with timeout 300, freq 75 seconds Dec 21 08:03:15 chandra automount[10227]: lookup_mount: lookup(program): /net/chandra/usr2 -> -fstype=nfs,hard,intr,nodev,nosuid chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid chandra:/usr2 Dec 21 08:03:15 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:15 chandra automount[10227]: sun_mount: parse(sun): mounting root /net/chandra/usr2, mountpoint /net/chandra/usr2, what chandra:/usr2, fstype nfs, options hard,intr,nodev,nosuid Dec 21 08:03:15 chandra automount[10227]: re-connected to /net/chandra/usr2 Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: re-connected to mount /net/chandra/usr2 Dec 21 08:03:15 chandra automount[10227]: re-connected to /net/chandra Dec 21 08:03:15 chandra automount[10227]: remount_active_mount: re-connected to mount /net Dec 21 08:03:15 chandra automount[10227]: st_ready: st_ready(): state = 0 path /net Dec 21 08:03:15 chandra systemd: Started Automounts filesystems on demand. Dec 21 08:03:18 chandra automount[10227]: handle_packet: type = 3 Dec 21 08:03:18 chandra automount[10227]: handle_packet_missing_indirect: token 657, name ares, request pid 9428 Dec 21 08:03:18 chandra automount[10227]: attempting to mount entry /net/ares Dec 21 08:03:18 chandra automount[10227]: lookup_mount: lookup(program): looking up ares Dec 21 08:03:18 chandra automount[10227]: lookup_mount: lookup(program): ares -> -fstype=nfs,hard,intr,nodev,nosuid /usr2 ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid /usr2 ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): dequote("/usr2") -> /usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mapent: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: parse_mapent: parse(sun): dequote("ares:/usr2") -> ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: update_offset_entry: parse(sun): updated multi-mount offset /usr2 -> -fstype=nfs,hard,intr,nodev,nosuid ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: do_mount_autofs_offset: mount offset /net/ares/usr2 at /net/ares Dec 21 08:03:18 chandra automount[10227]: mount_autofs_offset: calling mount -t autofs -s -o fd=13,pgrp=10227,minproto=5,maxproto=5,offset automount /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: mounted offset on /net/ares/usr2 with timeout 300, freq 75 seconds Dec 21 08:03:18 chandra automount[10227]: mount_autofs_offset: mounted trigger /net/ares/usr2 at /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: dev_ioctl_send_ready: token = 657 Dec 21 08:03:18 chandra automount[10227]: mounted /net/ares Dec 21 08:03:18 chandra automount[10227]: handle_packet: type = 5 Dec 21 08:03:18 chandra automount[10227]: handle_packet_missing_direct: token 658, name /net/ares/usr2, request pid 9428 Dec 21 08:03:18 chandra automount[10227]: attempting to mount entry /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: lookup_mount: lookup(program): /net/ares/usr2 -> -fstype=nfs,hard,intr,nodev,nosuid ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid ares:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: sun_mount: parse(sun): mounting root /net/ares/usr2, mountpoint /net/ares/usr2, what ares:/usr2, fstype nfs, options hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: mount_mount: mount(nfs): root=/net/ares/usr2 name=/net/ares/usr2 what=ares:/usr2, fstype=nfs, options=hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: mount_mount: mount(nfs): nfs options="hard,intr,nodev,nosuid", nobind=0, nosymlink=0, ro=0 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: called with host ares(129.112.10.73) proto 6 version 0x40 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: called with host ares(129.112.10.73) proto 6 version 0x70 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: nfs v3 rpc ping time: 0.000204 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: host ares cost 204 weight 0 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: called with host ares(129.112.10.73) proto 17 version 0x70 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: nfs v3 rpc ping time: 0.000246 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: nfs v2 rpc ping time: 0.000254 Dec 21 08:03:18 chandra automount[10227]: get_nfs_info: host ares cost 249 weight 0 Dec 21 08:03:18 chandra automount[10227]: prune_host_list: selected subset of hosts that support NFS3 over TCP Dec 21 08:03:18 chandra automount[10227]: mount_mount: mount(nfs): calling mkdir_path /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: mount_mount: mount(nfs): calling mount -t nfs -s -o hard,intr,nodev,nosuid ares:/usr2 /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:03:18 chandra rpc.idmapd[605]: New client: 1d9 Dec 21 08:03:18 chandra rpc.idmapd[605]: Stale client: 1d9 Dec 21 08:03:18 chandra rpc.idmapd[605]: -> closed /var/lib/nfs/rpc_pipefs//nfs/clnt1d9/idmap Dec 21 08:03:18 chandra rpc.idmapd[605]: New client: 1da Dec 21 08:03:18 chandra rpc.idmapd[605]: New client: 1db Dec 21 08:03:18 chandra automount[10227]: handle_packet: type = 3 Dec 21 08:03:18 chandra automount[10227]: handle_packet_missing_indirect: token 659, name kibo, request pid 18283 Dec 21 08:03:18 chandra automount[10227]: mount_mount: mount(nfs): mounted ares:/usr2 on /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: attempting to mount entry /net/kibo Dec 21 08:03:18 chandra automount[10227]: dev_ioctl_send_ready: token = 658 Dec 21 08:03:18 chandra automount[10227]: mounted /net/ares/usr2 Dec 21 08:03:18 chandra automount[10227]: lookup_mount: lookup(program): looking up kibo Dec 21 08:03:18 chandra automount[10227]: lookup_mount: lookup(program): kibo -> -fstype=nfs,hard,intr,nodev,nosuid /usr2 kibo:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid /usr2 kibo:/usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: parse_mount: parse(sun): dequote("/usr2") -> /usr2 Dec 21 08:03:18 chandra automount[10227]: parse_mapent: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:18 chandra automount[10227]: parse_mapent: parse(sun): dequote("kibo:/usr2") -> kibo:/usr2 Dec 21 08:03:19 chandra automount[10227]: update_offset_entry: parse(sun): updated multi-mount offset /usr2 -> -fstype=nfs,hard,intr,nodev,nosuid kibo:/usr2 Dec 21 08:03:19 chandra automount[10227]: do_mount_autofs_offset: mount offset /net/kibo/usr2 at /net/kibo Dec 21 08:03:19 chandra automount[10227]: mount_autofs_offset: calling mount -t autofs -s -o fd=13,pgrp=10227,minproto=5,maxproto=5,offset automount /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: mounted offset on /net/kibo/usr2 with timeout 300, freq 75 seconds Dec 21 08:03:19 chandra automount[10227]: mount_autofs_offset: mounted trigger /net/kibo/usr2 at /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: dev_ioctl_send_ready: token = 659 Dec 21 08:03:19 chandra automount[10227]: mounted /net/kibo Dec 21 08:03:19 chandra automount[10227]: handle_packet: type = 5 Dec 21 08:03:19 chandra automount[10227]: handle_packet_missing_direct: token 660, name /net/kibo/usr2, request pid 18283 Dec 21 08:03:19 chandra automount[10227]: attempting to mount entry /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: lookup_mount: lookup(program): /net/kibo/usr2 -> -fstype=nfs,hard,intr,nodev,nosuid kibo:/usr2 Dec 21 08:03:19 chandra automount[10227]: parse_mount: parse(sun): expanded entry: -fstype=nfs,hard,intr,nodev,nosuid kibo:/usr2 Dec 21 08:03:19 chandra automount[10227]: parse_mount: parse(sun): gathered options: fstype=nfs,hard,intr,nodev,nosuid Dec 21 08:03:19 chandra automount[10227]: sun_mount: parse(sun): mounting root /net/kibo/usr2, mountpoint /net/kibo/usr2, what kibo:/usr2, fstype nfs, options hard,intr,nodev,nosuid Dec 21 08:03:19 chandra automount[10227]: mount_mount: mount(nfs): root=/net/kibo/usr2 name=/net/kibo/usr2 what=kibo:/usr2, fstype=nfs, options=hard,intr,nodev,nosuid Dec 21 08:03:19 chandra automount[10227]: mount_mount: mount(nfs): nfs options="hard,intr,nodev,nosuid", nobind=0, nosymlink=0, ro=0 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: called with host kibo(129.112.10.54) proto 6 version 0x40 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: called with host kibo(129.112.10.54) proto 6 version 0x70 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: nfs v3 rpc ping time: 0.000140 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: host kibo cost 140 weight 0 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: called with host kibo(129.112.10.54) proto 17 version 0x70 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: nfs v3 rpc ping time: 0.000173 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: nfs v2 rpc ping time: 0.000170 Dec 21 08:03:19 chandra automount[10227]: get_nfs_info: host kibo cost 171 weight 0 Dec 21 08:03:19 chandra automount[10227]: prune_host_list: selected subset of hosts that support NFS3 over TCP Dec 21 08:03:19 chandra automount[10227]: mount_mount: mount(nfs): calling mkdir_path /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: mount_mount: mount(nfs): calling mount -t nfs -s -o hard,intr,nodev,nosuid kibo:/usr2 /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: spawn_mount: mtab link detected, passing -n to mount Dec 21 08:03:19 chandra rpc.idmapd[605]: New client: 1dc Dec 21 08:03:19 chandra rpc.idmapd[605]: Stale client: 1dc Dec 21 08:03:19 chandra rpc.idmapd[605]: -> closed /var/lib/nfs/rpc_pipefs//nfs/clnt1dc/idmap Dec 21 08:03:19 chandra rpc.idmapd[605]: New client: 1dd Dec 21 08:03:19 chandra rpc.idmapd[605]: New client: 1de Dec 21 08:03:19 chandra automount[10227]: mount_mount: mount(nfs): mounted kibo:/usr2 on /net/kibo/usr2 Dec 21 08:03:19 chandra automount[10227]: dev_ioctl_send_ready: token = 660 Dec 21 08:03:19 chandra automount[10227]: mounted /net/kibo/usr2 Dec 21 08:04:08 chandra dbus-daemon: dbus[483]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemManager1.service' Dec 21 08:04:08 chandra dbus[483]: [system] Activating via systemd: service name='org.freedesktop.ModemManager1' unit='dbus-org.freedesktop.ModemManager1.service' Dec 21 08:04:08 chandra dbus[483]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.ModemManager1.service': Unit dbus-org.freedesktop.ModemManager1.service failed to load: No such file or directory. Dec 21 08:04:08 chandra dbus-daemon: dbus[483]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.ModemManager1.service': Unit dbus-org.freedesktop.ModemManager1.service failed to load: No such file or directory.
I am experiencing the same problem. This is a regression from Fedora 20 release. Downgrading to autofs-5.0.7-29.fc20.x86_64.rpm fixes the problem for me. Also, I can only reproduce the problem trying to auto-mount filesystems exported from RHEL5. Mounting filesystems exported from Fedora 18 works fine. I think this bug should be reopened.
Created attachment 840639 [details] debug log mounting NFS filesystem exported from RHEL5
I'm seeing the same problem when mounting from RHEL5 sources. Attached journalctl entries with debug enabled (replaced my hostname with myhost and nfs-server hostname with nfs-host). Should we clone this report to a new one or reopen this one?
Created attachment 840957 [details] autofs debug output debug output in systemd journal when trying to mount an RHEL5 nfs export
(In reply to Kevin Gardner from comment #9) > Thanks, Ian - pointers much appreciated. I've followed as you suggested and > have captured debugging info which I've pasted in below. The log is broken > into two parts, both of which document chandra attempting to mount > ares:/usr2; an initial attempt is made with /net -hosts in /etc/auto.master > which is unsuccessful, while a subsequent attempt with /net /etc/auto.net > works fine. > > Holler if I can provide more info. > > Thanks, > Kevin > > (In reply to Ian Kent from comment #8) > > (In reply to Kevin Gardner from comment #7) > > > (In reply to Ian Kent from comment #6) > > > > (In reply to Kevin Gardner from comment #5) > > > > > Unfortunately, problem still exists in autofs-5.0.7-37.fc20 - just upgraded > > > > > from F19 yesterday and seeing the same issue. Workaround (switch /net > > > > > -hosts -> /net /etc/auto.net) still functional. > > > > > > > > Can you provide a full debug log please. > > > > > > Glad to. I'd appreciate a pointer or two re: which logs you'd like (and how > > > they're triggered, if not extracts from routine /var/log entries) to ensure > > > that I can get you the most useful information most quickly. Thanks --- > > > > Umm ... you need to ensure that the facility daemon is recording > > log level debug and above. > > > > I usually do that with: > > > > daemon.* /var/log/debug.log > > > > in the syslog (or rsyslog) configuration. > > > > Then you need to tell autofs to log debug output by setting the config > > entry LOGGING="debug" in /etc/sysconfig/autofs. > > ----- STOP AUTOFS, SWITCH TO /net -hosts, RESTART AND ATTEMPT TO MOUNT > ares:/usr2 Not sure what your trying to say here. snip ... > Dec 21 08:02:11 chandra automount[10204]: lookup_read_map: lookup(hosts): > read hosts map > Dec 21 08:02:11 chandra automount[10204]: lookup_read_map: lookup(hosts): > map not browsable, update existing host entries only > Dec 21 08:02:11 chandra automount[10204]: remount_active_mount: trying to > re-connect to mount /net > Dec 21 08:02:11 chandra automount[10204]: mounted indirect on /net with > timeout 300, freq 75 seconds > Dec 21 08:02:11 chandra automount[10204]: lookup_mount: lookup(hosts): > chandra -> (null) > Dec 21 08:02:11 chandra automount[10204]: get_exports: lookup(hosts): > fetchng export list for chandra > Dec 21 08:02:11 chandra automount[10204]: parse_mount: parse(sun): expanded > entry: "/usr/local" "chandra:/usr/local" "/usr2" "chandra:/usr2" Says that the exports list has been successfully retrieved from the server which is the problem addressed in this bug. snip ... > Dec 21 08:02:11 chandra automount[10204]: re-connected to /net/chandra > Dec 21 08:02:12 chandra automount[10204]: remount_active_mount: re-connected > to mount /net > Dec 21 08:02:12 chandra automount[10204]: st_ready: st_ready(): state = 0 > path /net And then nothing .... Are you saying that autofs doesn't get a request to perform a mount when you try and access the path or does it get a request and then fail? > ----- STOP AUTOFS, SWITCH TO /net /etc/auto.net, RESTART AND TRY AGAIN Umm ... there are problems with this trace but I'm not going to try and comment on them because the auto.net script hasn't been used for so long it isn't relevant any more. The internal hosts map has worked fine for a long time so we need to focus on finding where the problem is with that. Ian
Created attachment 841126 [details] Patch - fix rpc_portmap_getport() proto not set I think I see the problem. I'll build a package soon as I get time.
autofs-5.0.7-38.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/autofs-5.0.7-38.fc20
-38 still has the same problem: Dec 24 09:45:05 myhost automount[30962]: handle_packet: type = 3 Dec 24 09:45:05 myhost automount[30962]: handle_packet_missing_indirect: token 68, name nfs-host, request pid 31011 Dec 24 09:45:05 myhost automount[30962]: attempting to mount entry /net/nfs-host Dec 24 09:45:05 myhost automount[30962]: lookup_mount: lookup(hosts): nfs-host -> (null) Dec 24 09:45:05 myhost automount[30962]: get_exports: lookup(hosts): fetchng export list for nfs-host Dec 24 09:45:05 myhost automount[30962]: get_exports: lookup(hosts): exports lookup failed for nfs-host Dec 24 09:45:05 myhost automount[30962]: key "nfs-host" not found in map source(s). Dec 24 09:45:05 myhost automount[30962]: dev_ioctl_send_fail: token = 68 Dec 24 09:45:05 myhost automount[30962]: failed to mount /net/nfs-host Dec 24 09:45:05 myhost automount[30962]: handle_packet: type = 3 Dec 24 09:45:05 myhost automount[30962]: handle_packet_missing_indirect: token 69, name nfs-host, request pid 31011 Dec 24 09:45:05 myhost automount[30962]: dev_ioctl_send_fail: token = 69 Dec 24 09:45:05 myhost automount[30962]: handle_packet: type = 3 Dec 24 09:45:05 myhost automount[30962]: handle_packet_missing_indirect: token 70, name nfs-host, request pid 31011 Dec 24 09:45:05 myhost automount[30962]: dev_ioctl_send_fail: token = 70 At least I think it's the same problem.
(In reply to Fedora Update System from comment #16) > autofs-5.0.7-38.fc20 has been submitted as an update for Fedora 20. > https://admin.fedoraproject.org/updates/autofs-5.0.7-38.fc20 Same here, still the same problem.
Package autofs-5.0.7-38.fc20: * should fix your issue, * was pushed to the Fedora 20 testing repository, * should be available at your local mirror within two days. Update it with: # su -c 'yum update --enablerepo=updates-testing autofs-5.0.7-38.fc20' as soon as you are able to. Please go to the following url: https://admin.fedoraproject.org/updates/FEDORA-2013-23937/autofs-5.0.7-38.fc20 then log in and leave karma (feedback).
(In reply to Andy Wang from comment #17) > -38 still has the same problem: Unless we can work out what is different about your environment I can't reproduce this so can't resolve it. So tell me more about the client and server.
autofs-5.0.7-39.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/autofs-5.0.7-39.fc20
(In reply to Fedora Update System from comment #21) > autofs-5.0.7-39.fc20 has been submitted as an update for Fedora 20. > https://admin.fedoraproject.org/updates/autofs-5.0.7-39.fc20 I can confirm that this fixes it for me.
autofs-5.0.7-40.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/autofs-5.0.7-40.fc20
Yup, I skipped 39 and just tried 40 and problem solved. Thanks much for the quick fixes.
Good to hear. That was harder than it should have been, ;)
I've just fedup'd from F19 to F20 and came across this problem (and this bug report)... I can also confirm autofs-5.0.7-40.fc20 from the updates-testing repo has fixed the problem for me - thanks!!!
autofs-5.0.7-40.fc20 has been pushed to the Fedora 20 stable repository. If problems still persist, please make note of it in this bug report.
Same problem for me. I had already updated to autofs-5.0.7-40.fc20. Before reading this bugzilla entry I did a fresh reboot, and then tried starting and stopping autofs to no avail. Upon reading all the comments I simply did: yum remove autofs yum install autofs Auto fs then started working normally. It seems there is still a problem with updating from a previous version of autofs, but not when doing a fresh install. Bill
Sorry, I was mistaken. I just reviewed my update logs, and found I was at 1:5.0.7-37.fc20 when I did the "yum remove autofs" command. So an update to 1:5.0.7-40.fc20 would have probably worked just as well as the fresh install. Bill
autofs-5.0.7-41.fc20 has been submitted as an update for Fedora 20. https://admin.fedoraproject.org/updates/autofs-5.0.7-41.fc20
autofs-5.0.7-41.fc20 has been pushed to the Fedora 20 stable repository. If problems still persist, please make note of it in this bug report.