Unlocking existing session often requires several attempts.

[Stéphane Gourichon]

# Context

* Computer with several X sessions opened.
* Users switching from one opened session to another.
* Lightdm opens new greeter, wait for typing password.
* User types password.
* Password is accepted.
* System closes the current greeter (screen gets black for an instant).

# Expected

* User gets back to their already opened session.

# Observed

* System immediately opens another greeter.
* User has to type password again.

# Reproducible

* Not always. At times, often, at other times, rare.

# Additional information

Users switch session via
dm-tool switch-to-user $OTHERUSER
but I guess bug appears with other means (like menu item like "lock screen", etc).

# Information requested

lsb_release -rd

Description: Ubuntu 18.04 LTS
Release: 18.04

LC_ALL=C apt-cache policy lightdm

lightdm:
  Installed: 1.26.0-0ubuntu1
  Candidate: 1.26.0-0ubuntu1
  Version table:
 *** 1.26.0-0ubuntu1 500
        500 http://fr.archive.ubuntu.com/ubuntu bionic/universe amd64 Packages
        100 /var/lib/dpkg/status

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: lightdm 1.26.0-0ubuntu1
ProcVersionSignature: Ubuntu 4.15.0-23.25-generic 4.15.18
Uname: Linux 4.15.0-23-generic x86_64
ApportVersion: 2.20.9-0ubuntu7.2
Architecture: amd64
Date: Tue Jun 12 14:14:52 2018
ExecutablePath: /usr/sbin/lightdm
InstallationDate: Installed on 2018-05-25 (18 days ago)
InstallationMedia: Xubuntu 18.04 LTS "Bionic Beaver" - Release amd64 (20180426)
ProcEnviron:
 LANG=fr_FR.UTF-8
 PATH=(custom, no user)
SourcePackage: lightdm
UpgradeStatus: No upgrade log present (probably fresh install)
modified.conffile..etc.logrotate.d.lightdm: [modified]
mtime.conffile..etc.logrotate.d.lightdm: 2018-05-25T06:19:22.081830

[Stéphane Gourichon (stephane-gourichon-lpad)]

As seen in attached files, this is Xubuntu 18.04, where lightdm is default, no significant local customization.

[Stéphane Gourichon (stephane-gourichon-lpad)]

Bug still regularly observed.

This is not the same bug as #1656399 though it share some characteristics.

In particular, the fact that both bugs do not always occur (but somehow randomly) suggests that both are linked to a race condition somewhere in lightdm logic.

[Stéphane Gourichon (stephane-gourichon-lpad)]

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 n551...

[Stéphane Gourichon (stephane-gourichon-lpad)]

Summary: twice, bug happened when service org.gtk.vfs.Daemon is activating *after* org.a11y.atspi.Registry is activated.

Details below.

Bug just happened again on unlocking session (versus switching users).

I compared the output of journalctl.

## Around unlock time: nothing to see

Around unlock time, journalctl only shows lightdm cleanup activity. Then, only when bug happens, lightdm starts again the whole sequence :

systemd[somepid]: Starting User Manager for UID 110...
systemd-logind[749]: New session c9 of user lightdm.
systemd[somepid]: Started Session c9 of user lightdm.
...

## Around lock time: same correlation between log order and bug occurrence

Again

Indeed, bug happens when log is in this order:

at-spi-bus-launcher[25560]: dbus-daemon[25565]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=110 pid=25557 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
at-spi-bus-launcher[25560]: dbus-daemon[25565]: Successfully activated service 'org.a11y.atspi.Registry'
at-spi-bus-launcher[25560]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
dbus-daemon[25559]: [session uid=110 pid=25559] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.4' (uid=110 pid=25557 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")

and things go smoothly when log is in this order:

at-spi-bus-launcher[15685]: dbus-daemon[15690]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=110 pid=15682 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
dbus-daemon[15684]: [session uid=110 pid=15684] Activating via systemd: service name='org.gtk.vfs.Daemon' unit='gvfs-daemon.service' requested by ':1.3' (uid=110 pid=15682 comm="/usr/sbin/lightdm-gtk-greeter " label="unconfined")
at-spi-bus-launcher[15685]: dbus-daemon[15690]: Successfully activated service 'org.a11y.atspi.Registry'
at-spi-bus-launcher[15685]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry

Summary: twice, bug happened when service org.gtk.vfs.Daemon is activating *after* org.a11y.atspi.Registry is activated.

[Stéphane Gourichon (stephane-gourichon-lpad)]

Sometimes a variant of the bug happens: after typing password, the expected session does not happen. Instead, a black screen with a white message on center, saying that session is locked and I have to wait for a moment. About 20 seconds later, a lightdm login greeter appears and only after typing the correct password *again*, I can access my session.

I just experienced that variant and captured logs (journalctl) of it. I compared with journalctl logs when unlocking. Again, I don't see anything really salient in logs. I can post them here if useful.

Any hint appreciated. Thanks.

[Stéphane Gourichon (stephane-gourichon-lpad)]

So far, the logs basically show that lightdm does its job, and just does it again when bug happens.

I have the feeling that the actual reason of the bug does not appear in the log.

Perhaps something triggers a lock behavior, causing lightdm to just do what it's supposed to do.

The problem might lie in light-locker or something else.

Will continue investigating.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Vladyslav Drok (vdrok)]

Using lightdm 1.26.0 in arch with xfce, and experiencing the same behaviour as described in comment #7, with no errors in the logs. In my case the delay between "session is locked" message and actual greeter appearance is around 10 seconds.

[Stéphane Gourichon (stephane-gourichon-lpad)]

I have a question for people experiencing this bug (yes, you included :-).

Please:

* open xfce4-settings-manager,
* click icon "power manager",
* click tab "security",
* report what settings are there for when to "automatically lock the session", "delay locking after screensaver for...", "lock screen when system is going to sleep"
* if the bug affects you,
* and your exact distribution version.

Also, since you have to login to launchpad to comment here, please answer to "does this bug affect you?" question on top of this page.

This will help me figure out a proper fix.

Thanks!

[Vladyslav Drok (vdrok)]

Hey gouri, here is the info you requested:

automatically lock the session - when the screensaver is activated
delay locking after screensaver for - 5 seconds
lock screen when system is going to sleep - checked

marked the bug as affecting me

as I said I'm using archlinux, it's just the place I found with someone hitting this issue, here are some package and kernel versions if this is of any help:

local/xfdesktop 4.12.4-2 (xfce4)
    A desktop manager for Xfce
local/xfwm4 4.12.5-1 (xfce4)
    Xfce window manager
local/xfce4-session 4.12.1-8 (xfce4)
    A session manager for Xfce
local/light-locker 1.8.0-2
    A simple session locker for LightDM
local/lightdm 1:1.28.0-1
    A lightweight display manager
local/lightdm-gtk-greeter 1:2.0.6-1
    GTK+ greeter for LightDM
local/lightdm-gtk-greeter-settings 1.2.2-3
    Settings editor for the LightDM GTK+ Greeter
local/gtk-xfce-engine 2.10.1-2 (xfce4)
    Xfce Gtk+-2.0 engine and themes
local/gtk2 2.24.32-1
    GObject-based multi-platform GUI toolkit (legacy)
local/gtk3 3.24.1+8+g220f77d8c1-1
    GObject-based multi-platform GUI toolkit

Linux carbon 4.19.8-arch1-1-ARCH #1 SMP PREEMPT Sat Dec 8 13:49:11 UTC 2018 x86_64 GNU/Linux

[Magesh Dhasayyan (mag3sh)]

I had the exact same issue. In my case, I upgraded xubuntu 16.04 to 18.04 and this issue started showing up. Pulseaudio was also not working.
From further investigation, I noticed that chrome-remote-desktop was starting Xsession and this was causing issues. I removed that package and it fixed the issue.

[Stéphane Gourichon (stephane-gourichon-lpad)]

## Thanks @vdrok

> automatically lock the session - when the screensaver is activated
> delay locking after screensaver for - 5 seconds
> lock screen when system is going to sleep - checked

Hmm, on my system the delay was set to something small (perhaps even 0).

## Thanks @mag3sh

> From further investigation, I noticed that chrome-remote-desktop was starting Xsession and this was causing issues. I removed that package and it fixed the issue.

I have no such thing as `chrome-remote-desktop` on my machine.

## Workaround (works for me)

This workaround was suggested by the fact that logs say everyting is fine. Perhaps the session happens to be locked again before even displaying?

* open xfce4-settings-manager,
* click icon "power manager",
* click tab "security",

Set like this :

* automatically lock the session - when the screensaver is activated
* delay locking after screensaver for - **15** seconds
* lock screen when system is going to sleep - checked

Thank you for your attention.

[Jane Atkinson (irihapeti)]

This seems to have reappeared recently in Xubuntu 20.04

[Ubuntu QA Website (ubuntuqa)]

This bug has been reported on the Ubuntu ISO testing tracker.

A list of all reports related to this bug can be found here:
http://iso.qa.ubuntu.com/qatracker/reports/bugs/1776475

[Stéphane Gourichon (stephane-gourichon-lpad)]

Thank You Jane @irihapeti for your message.

Can you be more specific about the sequence of events and symptom observed?

Also, can you tell:
(1) the parameters mentioned on comment #11
and (2) whether following the workaround on comment #14 works for you?

This may be very helpful to fix the bug once and for all.

Thanks!

[Jane Atkinson (irihapeti)]

@Stéphane: Sorry, I didn't see this sooner. I must have forgotten to subscribe. (oops)

In Xubuntu Final (iso 20200420.1), there is no Security tab in the Power Manager. Only a "security" checkbox which controls "Lock screen when system is going to sleep". I had a look in the configuration editor in case something was hiding there - nothing relevant there.

My sequence of actions is:

*Create new user.
*Open a program (usually Thunar or Terminal).
*Lock session.
*Log in as new user which I just created.
*Log out of new user's session.
*Select my original user.
*Enter password to unlock.
*Then there's a delay and screen goes black, then the unlock prompt appears again.
*The second time, the original session unlocks.

It's occurred to me that this just might be an issue with the QEMU/KVM vm, if no one else is having problems. I don't have a spare machine for testing, unfortunately, though I might be able to do something with an external drive. If I get a chance later today, I see what I can do.

[Jane Atkinson (irihapeti)]

A fresh install on an external USB3 drive is showing exactly the same behaviour. Not a VM problem, apparently.

[Stéphane Gourichon (stephane-gourichon-lpad)]

Hi Jane @irihapeti.

Thank you for reporting.

The settings
"delay locking after screensaver for..."
that was in
"Power Manager" settings,
tab "Security"
may correspond to what exists in 20.04 in
"Screensaver" settings,
tab "Lock Screen", and renamed to
"Lock the screen after the screen saver is active for..."

Can you report the current value? (presumably zero)
And set it to one minute to see if it fixes your problem?

Thanks!

[Jane Atkinson (irihapeti)]

The default value was 0 minutes. I set it to one minute and it made no difference.

Incidentally, it seems that clicking on the "Switch user" button is enough to trigger the problem. I did this because I couldn't remember whether or not I'd added another user (I hadn't at that point). It's not necessary to actually log in as the other user.

[Stéphane Gourichon (stephane-gourichon-lpad)]

Thank you for this extra information. This allowed to narrow down the bug you experienced to a simplified, shorter bug scenario.

I was suspecting that this may not be the same bug.

> It's not necessary to actually log in as the other user.

The bug discussed here only happens when the user is already logged in.

May I suggest that you open a new bug report with details of a minimal reproducible case?

Thank you for your attention.

[Jane Atkinson (irihapeti)]

I've opened a new bug report: Bug #1874178

I'll mark myself as not affected by this one.