Comment 4 for bug 1776475

In order to investigate this bug, I started to write down each time I switch user and whether it works.

The time information allowed to obtain time-bounded log extracts that focus on relevant parts using journalctl --since ... --until ... .

After 3 "work" and one "fail" case, I observed a correlation, which might or might not be relevant.

## Logs when no bug, things work

The following log sequence happens all 3 times things work okay:

2018-07-24T13:00:38.327651+0200 n551jk systemd[16387]: Startup finished in 26ms.
2018-07-24T13:00:38.327693+0200 n551jk systemd[1]: Started User Manager for UID 110.
2018-07-24T13:00:38.360247+0200 n551jk systemd[16387]: Started D-Bus User Message Bus.
2018-07-24T13:00:38.363237+0200 n551jk dbus-daemon[16407]: [session uid=110 pid=16407] AppArmor D-Bus mediation is enabled
2018-07-24T13:00:38.363739+0200 n551jk dbus-daemon[16407]: [session uid=110 pid=16407] Activating via systemd: service name='org.a11y.Bus' unit='at-spi-dbus-bus.service' requested by ':1.1' (uid=110 pid=16405 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T13:00:38.364556+0200 n551jk systemd[16387]: Starting Accessibility services bus...
2018-07-24T13:00:38.368461+0200 n551jk dbus-daemon[16407]: [session uid=110 pid=16407] Successfully activated service 'org.a11y.Bus'
2018-07-24T13:00:38.368546+0200 n551jk systemd[16387]: Started Accessibility services bus.
2018-07-24T13:00:38.371337+0200 n551jk at-spi-bus-launcher[16408]: dbus-daemon[16413]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=110 pid=16405 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T13:00:38.373982+0200 n551jk dbus-daemon[16407]: [session uid=110 pid=16407] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=110 pid=16405 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T13:00:38.374774+0200 n551jk at-spi-bus-launcher[16408]: dbus-daemon[16413]: Successfully activated service 'org.a11y.atspi.Registry'
2018-07-24T13:00:38.374918+0200 n551jk at-spi-bus-launcher[16408]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
2018-07-24T13:00:38.375082+0200 n551jk systemd[16387]: Starting Virtual filesystem service...

## Logs when bug happens, things fail

The bug happened once since I started to write down each operation, and it shows a difference:

2018-07-24T16:34:15.777621+0200 n551jk systemd[23296]: Startup finished in 23ms.
2018-07-24T16:34:15.777665+0200 n551jk systemd[1]: Started User Manager for UID 110.
2018-07-24T16:34:15.820108+0200 n551jk systemd[23296]: Started D-Bus User Message Bus.
2018-07-24T16:34:15.822959+0200 n551jk dbus-daemon[23316]: [session uid=110 pid=23316] AppArmor D-Bus mediation is enabled
2018-07-24T16:34:15.823499+0200 n551jk dbus-daemon[23316]: [session uid=110 pid=23316] Activating via systemd: service name='org.a11y.Bus' unit='at-spi-dbus-bus.service' requested by ':1.1' (uid=110 pid=23314 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T16:34:15.824373+0200 n551jk systemd[23296]: Starting Accessibility services bus...
2018-07-24T16:34:15.828552+0200 n551jk dbus-daemon[23316]: [session uid=110 pid=23316] Successfully activated service 'org.a11y.Bus'
2018-07-24T16:34:15.828659+0200 n551jk systemd[23296]: Started Accessibility services bus.
2018-07-24T16:34:15.831689+0200 n551jk at-spi-bus-launcher[23317]: dbus-daemon[23322]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=110 pid=23314 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T16:34:15.835154+0200 n551jk at-spi-bus-launcher[23317]: dbus-daemon[23322]: Successfully activated service 'org.a11y.atspi.Registry'
2018-07-24T16:34:15.835289+0200 n551jk at-spi-bus-launcher[23317]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
2018-07-24T16:34:15.835578+0200 n551jk dbus-daemon[23316]: [session uid=110 pid=23316] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.4' (uid=110 pid=23314 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
2018-07-24T16:34:15.836417+0200 n551jk systemd[23296]: Starting Virtual filesystem service...

## Difference between "work" and "fail"

All 3 lines mentioning at-spi-bus-launcher come *before* : dbus-daemon ... Activating via systemd: service name='org.gtk.vfs.Daemon'.

I don't know it this is relevant at this point in time.

No other salient difference in logs.

Logs attached.