Bug#973474: gnome: Unable to log back in in after screen lock

[Simon McVittie]

On Mon, 01 Mar 2021 at 22:48:47 +0100, Marcin Owsiany wrote:
> I installed from debian-bullseye-DI-alpha3-amd64-netinst.iso in virt-manager VM
> with 2 VCPUs and 4GB of RAM.
> Other than selecting Polish locale and installing ssh server and all possible
> display managers and window environments that debian-installer allows I don't
> remember doing anything special.

I hope that's pl_PL.UTF-8 rather than a non-Unicode character set?

Installing all possible desktop environments probably results in each
desktop environment having a "thundering herd" of session services all
trying to jump in and do similar things at around the same time, so it
doesn't entirely surprise me if some of them end up fighting.
Unfortunately, the same pile of extra processes also obscures what is
going on in the log.

> To verify, I subsequently (without rebooting the VM) logged into and out of
> Cinnamon session once more, and then logged into the GNOME session again
> (without running the logger commands this time), and WAS able to reproduce the
> issue. 
> 
> I have a full output of journalctl for that run of the VM, at [8]https://
> people.debian.org/~porridge/journal.txt.gz 

At what time did you log into and out of Cinnamon, and at what time did you
log into GNOME?

If they are the last ones in the log, then the timeline is:

22:22:47 start to log in to Cinnamon on tty4, logind session 13
22:22:58 gdm greeter on tty1 exits
22:23:02 log out from Cinnamon
22:23:03 gdm vt-switches back to tty1 and launches a new greeter
22:23:08 logind session 13 ends
22:23:16 start to log in to GNOME (session 15)

This is where it gets confusing. systemd --user process 23531 seems to be
trying to start a GNOME Shell session on Wayland and on X11 simultaneously
(or something?) and then at 22:23:19 we see:

> mar 01 22:23:19 debian gnome-shell[25939]: JS ERROR: Could not get a proxy for the current session: Gio.IOErrorEnum: GDBus.Error:org.freedesktop.login1.NoSuchSession: No session '13' known
>                                            asyncCallback at resource:///org/gnome/gjs/modules/core/overrides/Gio.js:131:23

This means gnome-shell somehow thinks it's part of session 13 - perhaps
because it's being run as a `systemd --user` per-user service, and your
systemd --user instance still has traces of session 13 left over?

But, meanwhile, at around the same time, the part of gnome-shell that is
a polkit (policykit) agent connects to polkitd, and polkitd correctly
identifies it as belonging to session 15...

We end up with a GNOME Wayland session (was that deliberate?)

Then at 22:23:24 you log in via ssh and log "before-lock2".

At 22:23:31, the gdm greeter exits.

At 22:23:34, gdm unlocks the login keyring. Was that you trying to unlock
the locked screen?

At 22:23:49, you log in via ssh to log "stuck".

This looks to me as though there were enough lingering processes from
session 13 that the gnome-shell that should be for session 15 somehow thinks
it is part of session 15. I think that might be the root cause for the lock
screen not unlocking: if GNOME Shell and gdm disagree on what the Shell's
session ID is, then GNOME Shell telling gdm "please unlock session 13" or
gdm telling GNOME Shell "if you are session 13, then please unlock" is
not going to have the desired effect.

If you can get the system into this state again, please look for the above
message in the log, and then try to ssh in and run:

    sudo loginctl
    sudo loginctl unlock-session 13

replacing 13 with the session ID from the error message. That might
unlock the screen, or might at least give some useful information. Or,
if it doesn't, try using a higher session ID.

Some other notes from your log:

> sty 29 14:36:04 debian light-locker[21349]: Environment variable XDG_SESSION_PATH not set. Is LightDM running?
> sty 29 14:36:04 debian kernel: traps: light-locker[21349] trap int3 ip:7f448fb2cb77 sp:7fffe5de5cf0 error:0 in libglib-2.0.so.0.6600.4[7f448faf0000+88000]

That's a crash, probably caused by calling g_error(). I don't know whether
light-locker is supposed to do anything useful on a system where lightdm
is not the selected display manager (and gdm is being used instead), but
it should probably at least exit gracefully instead of crashing itself.

When you first log in to GNOME, there's also a lot of this:

> sty 29 14:19:20 debian gnome-shell[1269]: Object St.BoxLayout (0x556bd28b1150), has been already deallocated — impossible to access it. This might be caused by the object having been destroyed from C code using something such as destroy(), dispose(), or remove() vfuncs.

Then later, there's a lot of this:

> sty 29 14:33:41 debian gnome-shell[1269]: Attempting to call back into JSAPI during the sweeping phase of GC. This is most likely caused by not destroying a Clutter actor or Gtk+ widget with ::destroy signals connected, but can also be caused by using the destroy(), dispose(), or remove() vfuncs. Because it would crash the application, it has been blocked and the JS callback not invoked.

Neither is good, but hopefully they're harmless.

    smcv