[Bug 1728055] Re: GDM3 hangs, if local home directory is not accessible

Sat Oct 28 14:26:04 UTC 2017

This bug seems not to be related to GDM at all. This is a problem either
with automount, or mount.nfs4.

I did spend some time today digging around this and found out that the
hang lasts for several minutes, but then the system springs back to life
and the user list in the greeter will get populated.

Related stuff from journald (user testuser is an LDAP user, remote home; user localadmin is local - his home is not accessible):
okt 28 16:07:17 paulus systemd[1]: Starting GNOME Display Manager...
okt 28 16:07:17 paulus systemd[1]: Started Regular background program processing daemon.
okt 28 16:07:17 paulus automount[1566]: Starting automounter version 5.1.2, master map /etc/auto.master
okt 28 16:07:17 paulus automount[1566]: using kernel protocol version 5.02
okt 28 16:07:17 paulus automount[1566]: lookup_nss_read_master: reading master file /etc/auto.master
okt 28 16:07:17 paulus automount[1566]: do_init: parse(sun): init gathered global options: (null)
okt 28 16:07:17 paulus systemd[1]: Started GNOME Display Manager.
okt 28 16:07:17 paulus automount[1566]: lookup_read_master: lookup(file): read entry /home
okt 28 16:07:17 paulus automount[1566]: master_do_mount: mounting /home
okt 28 16:07:17 paulus automount[1566]: automount_path_to_fifo: fifo name /var/run/autofs.fifo-home
okt 28 16:07:17 paulus automount[1566]: lookup_nss_read_map: reading map file /etc/auto.home
okt 28 16:07:17 paulus automount[1566]: do_init: parse(sun): init gathered global options: (null)
okt 28 16:07:18 paulus automount[1566]: mounted indirect on /home with timeout 300, freq 75 seconds
okt 28 16:07:18 paulus automount[1566]: st_ready: st_ready(): state = 0 path /home
okt 28 16:07:18 paulus systemd[1]: Started Automounts filesystems on demand.
okt 28 16:07:18 paulus systemd[1]: Reached target Multi-User System.
okt 28 16:07:18 paulus systemd[1]: Reached target Graphical Interface.
********SNIP
okt 28 16:07:37 paulus automount[1566]: handle_packet: type = 3
okt 28 16:07:37 paulus automount[1566]: handle_packet_missing_indirect: token 2, name testuser, request pid 1805
okt 28 16:07:37 paulus automount[1566]: attempting to mount entry /home/testuser
okt 28 16:07:37 paulus automount[1566]: lookup_mount: lookup(file): looking up testuser
okt 28 16:07:37 paulus automount[1566]: lookup_mount: lookup(file): testuser -> -fstype=nfs4,rw,intr,sec=krb5 petrus.(REDACTED):/home/&
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): expanded entry: -fstype=nfs4,rw,intr,sec=krb5 petrus.(REDACTED):/home/testuser
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): gathered options: fstype=nfs4,rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): dequote("petrus.(REDACTED):/home/testuser") -> petrus.(REDACTED):/home/testuser
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): core of entry: options=fstype=nfs4,rw,intr,sec=krb5, loc=petrus.(REDACTED):/home/testuser
okt 28 16:07:37 paulus automount[1566]: sun_mount: parse(sun): mounting root /home, mountpoint testuser, what petrus.(REDACTED):/home/testuser, fstype nfs4, options rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): root=/home name=testuser what=petrus.(REDACTED):/home/testuser, fstype=nfs4, options=rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): nfs options="rw,intr,sec=krb5", nobind=0, nosymlink=0, ro=0
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: called with host petrus.(REDACTED)(10.0.1.98) proto 6 version 0x40
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: nfs v4 rpc ping time: 0.000000
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: host petrus.(REDACTED) cost 0 weight 0
okt 28 16:07:37 paulus automount[1566]: prune_host_list: selected subset of hosts that support NFS4 over TCP
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): calling mkdir_path /home/testuser
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): calling mount -t nfs4 -s -o rw,intr,sec=krb5 petrus.(REDACTED):/home/testuser /home/testuser
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): mounted petrus.(REDACTED):/home/testuser on /home/testuser
okt 28 16:07:37 paulus automount[1566]: dev_ioctl_send_ready: token = 2
okt 28 16:07:37 paulus automount[1566]: mounted /home/testuser
okt 28 16:07:37 paulus automount[1566]: st_readmap: state 1 path /home
okt 28 16:07:37 paulus automount[1566]: re-reading map for /home
okt 28 16:07:37 paulus automount[1566]: lookup_nss_read_map: reading map file /etc/auto.home
okt 28 16:07:37 paulus automount[1566]: do_init: parse(sun): init gathered global options: (null)
okt 28 16:07:37 paulus automount[1566]: st_ready: st_ready(): state = 4 path /home
okt 28 16:07:37 paulus automount[1566]: handle_packet: type = 3
okt 28 16:07:37 paulus automount[1566]: handle_packet_missing_indirect: token 3, name localadmin, request pid 1805
okt 28 16:07:37 paulus automount[1566]: attempting to mount entry /home/localadmin
okt 28 16:07:37 paulus automount[1566]: lookup_mount: lookup(file): looking up localadmin
okt 28 16:07:37 paulus automount[1566]: lookup_mount: lookup(file): localadmin -> -fstype=nfs4,rw,intr,sec=krb5 petrus.(REDACTED):/home/&
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): expanded entry: -fstype=nfs4,rw,intr,sec=krb5 petrus.(REDACTED):/home/localadmin
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): gathered options: fstype=nfs4,rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): dequote("petrus.(REDACTED):/home/localadmin") -> petrus.(REDACTED):/home/localadmin
okt 28 16:07:37 paulus automount[1566]: parse_mount: parse(sun): core of entry: options=fstype=nfs4,rw,intr,sec=krb5, loc=petrus.(REDACTED):/home/localadmin
okt 28 16:07:37 paulus automount[1566]: sun_mount: parse(sun): mounting root /home, mountpoint localadmin, what petrus.(REDACTED):/home/localadmin, fstype nfs4, options rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): root=/home name=localadmin what=petrus.(REDACTED):/home/localadmin, fstype=nfs4, options=rw,intr,sec=krb5
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): nfs options="rw,intr,sec=krb5", nobind=0, nosymlink=0, ro=0
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: called with host petrus.(REDACTED)(10.0.1.98) proto 6 version 0x40
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: nfs v4 rpc ping time: 0.000000
okt 28 16:07:37 paulus automount[1566]: get_nfs_info: host petrus.(REDACTED) cost 0 weight 0
okt 28 16:07:37 paulus automount[1566]: prune_host_list: selected subset of hosts that support NFS4 over TCP
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): calling mkdir_path /home/localadmin
okt 28 16:07:37 paulus automount[1566]: mount_mount: mount(nfs): calling mount -t nfs4 -s -o rw,intr,sec=krb5 petrus.(REDACTED):/home/localadmin /home/localadmin
okt 28 16:07:37 paulus systemd[1]: Starting Preprocess NFS configuration...
okt 28 16:07:37 paulus systemd[1]: Started Preprocess NFS configuration.
okt 28 16:07:37 paulus systemd[1]: Starting NFS status monitor for NFSv2/3 locking....
okt 28 16:07:37 paulus systemd[1]: Starting Notify NFS peers of a restart...
okt 28 16:07:37 paulus rpc.statd[2086]: Version 1.3.3 starting
okt 28 16:07:37 paulus rpc.statd[2086]: Flags: TI-RPC
okt 28 16:07:37 paulus systemd[1]: Started NFS status monitor for NFSv2/3 locking..
okt 28 16:07:37 paulus sm-notify[2085]: Version 1.3.3 starting
okt 28 16:07:37 paulus systemd[1]: Started Notify NFS peers of a restart.
okt 28 16:08:43 paulus automount[1566]: st_expire: state 1 path /home
okt 28 16:08:43 paulus automount[1566]: expire_proc: exp_proc = 140083215357696 path /home
okt 28 16:08:43 paulus automount[1566]: expire_proc_indirect: expire /home/testuser
okt 28 16:08:43 paulus automount[1566]: 1 remaining in /home
okt 28 16:08:43 paulus automount[1566]: expire_cleanup: got thid 140083215357696 path /home stat 3
okt 28 16:08:43 paulus automount[1566]: expire_cleanup: sigchld: exp 140083215357696 finished, switching from 2 to 1
okt 28 16:08:43 paulus automount[1566]: st_ready: st_ready(): state = 2 path /home
okt 28 16:09:48 paulus automount[1566]: >> mount.nfs4: Connection timed out
okt 28 16:09:48 paulus automount[1566]: mount(nfs): nfs: mount failure petrus.(REDACTED):/home/localadmin on /home/localadmin
okt 28 16:09:48 paulus automount[1566]: dev_ioctl_send_fail: token = 3
okt 28 16:09:48 paulus automount[1566]: failed to mount /home/localadmin
okt 28 16:09:48 paulus automount[1566]: st_readmap: state 1 path /home
okt 28 16:09:48 paulus automount[1566]: re-reading map for /home
okt 28 16:09:48 paulus automount[1566]: lookup_nss_read_map: reading map file /etc/auto.home
okt 28 16:09:48 paulus automount[1566]: do_init: parse(sun): init gathered global options: (null)
okt 28 16:09:48 paulus automount[1566]: lookup_prune_one_cache: prune check posponed, /home/testuser mounted
okt 28 16:09:48 paulus automount[1566]: st_ready: st_ready(): state = 4 path /home
okt 28 16:09:58 paulus automount[1566]: st_expire: state 1 path /home
okt 28 16:09:58 paulus automount[1566]: expire_proc: exp_proc = 140083138111232 path /home
okt 28 16:09:58 paulus automount[1566]: expire_proc_indirect: expire /home/testuser
okt 28 16:09:58 paulus automount[1566]: 1 remaining in /home
okt 28 16:09:58 paulus automount[1566]: expire_cleanup: got thid 140083138111232 path /home stat 3
okt 28 16:09:58 paulus automount[1566]: expire_cleanup: sigchld: exp 140083138111232 finished, switching from 2 to 1
okt 28 16:09:58 paulus automount[1566]: st_ready: st_ready(): state = 2 path /home

This also happens when someone uses a text terminal and tries to login
with a local user (again - the directory is not accessible), or tries to
access certain settings within the graphical environment. While in the
terminal you can still see the cursor blinking, etc, but within the
graphical environment the whole computer freezes (the mouse cursor does
not move, you can't switch the num lock, etc) and because of the long
timeout people may prematurely try to hard reset the system, which can
lead to data loss...

This bug may be related to Bug #1050021 and Bug #234480

I didn't find any other workaround then the one mentioned above, which
does at least enable folks to login without spending extended periods of
time watching YT videos on their phones etc. :-)

** Package changed: gdm3 (Ubuntu) => autofs (Ubuntu)

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to autofs in Ubuntu.
https://bugs.launchpad.net/bugs/1728055

Title:
  GDM3 hangs, if local home directory is not accessible

Status in autofs package in Ubuntu:
  New

Bug description:
  In Ubuntu 17.10 with GDM 3.26.1-3ubuntu3, the greeter will hang, if
  local /home directory is not accessible.

  Our setup:
  - Ubuntu Server (16.04) with DNS, LDAP, Kerberos 5 and NFS servers. The home directories are present on the server and made available via NFS with krb5 authentication. LDAP provides the user data for clients.
  - Ubuntu client (17.10), bound to the server, uses AutoFS to automount remote home directories under /home. This makes the otherwise present local user directories unaccessible.

  Expected behaviour: After system startup, the greeter should provide a way for users to log in.
  Actual behaviour: The system hangs before the greeter displays the user list (but it does display the top menu bar and Ubuntu logo at the bottom).

  Additional remarks:
  If the settings for local users under /var/lib/AccountsService/users contain SystemAccount=true, the greeter will work as expected (while not displaying local users). This is a workaround, that I'm using right now. BUT: if the network user will log in and invoke the authentication dialog for system-wide settings (e.g. if he will try to add a new printer, or change the system update settings), the system will hang before displaying the expected dialog window. Also if a local user will try to log in by entering his login name and password, the system will hang (it should either produce an error message, or log in without a home directory).

  AutoFS uses this line to mount the remote home directories under /home:
  * -fstype=nfs4,rw,intr,sec=krb5 FQDN:/home/&

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/autofs/+bug/1728055/+subscriptions