Unlocking existing session often requires several attempts.

Bug #1776475 reported by Stéphane Gourichon
24
This bug affects 4 people
Affects Status Importance Assigned to Milestone
lightdm (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

# 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

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :
Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :
Download full text (4.5 KiB)

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

Read more...

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :
Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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.

Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in lightdm (Ubuntu):
status: New → Confirmed
Revision history for this message
Vladyslav Drok (vdrok) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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!

Revision history for this message
Vladyslav Drok (vdrok) wrote :

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

Revision history for this message
Magesh Dhasayyan (mag3sh) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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

Revision history for this message
Jane Atkinson (irihapeti) wrote :

This seems to have reappeared recently in Xubuntu 20.04

Revision history for this message
Ubuntu QA Website (ubuntuqa) wrote :

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

tags: added: iso-testing
Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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!

Revision history for this message
Jane Atkinson (irihapeti) wrote :

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

Revision history for this message
Jane Atkinson (irihapeti) wrote :

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

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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!

Revision history for this message
Jane Atkinson (irihapeti) wrote :

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.

Revision history for this message
Stéphane Gourichon (stephane-gourichon-lpad) wrote :

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.

Revision history for this message
Jane Atkinson (irihapeti) wrote :

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

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

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.