Hi again, wt., 2 mar 2021 o 02:31 Simon McVittie <s...@debian.org> napisaĆ(a):
> 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? > Yes, the latin2 nightmare is long gone :-) > 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. > Right. I made yet another attempt to reproduce this, aiming for as short a journal log as I could. The result is "just" 2570 lines this time. https://people.debian.org/~porridge/journal3.txt It also includes "logger" markers which I made from a single ssh session, which helps reduce the overall number of sessions. It might serve better as a minimal repro for filing an upstream bug. $ egrep --color 'Session [0-9a-f]|porridge\[[0-9]*\]:' journal3.txt mar 02 22:37:39 debian systemd[1]: Started Session c1 of user Debian-gdm. mar 02 22:38:10 debian systemd[1]: Started Session 2 of user porridge. mar 02 22:38:22 debian porridge[5608]: ssh-logged-in mar 02 22:38:35 debian porridge[5615]: cinnamon-starting-login mar 02 22:38:36 debian systemd[1]: Started Session 4 of user porridge. mar 02 22:38:47 debian systemd-logind[465]: Session c1 logged out. Waiting for processes to exit. mar 02 22:38:49 debian porridge[7641]: cinnamon-starting-logout mar 02 22:38:50 debian systemd-logind[465]: Session 4 logged out. Waiting for processes to exit. mar 02 22:38:50 debian systemd[1]: Started Session c2 of user Debian-gdm. mar 02 22:39:02 debian porridge[7905]: gnome-starting-login mar 02 22:39:04 debian systemd[1]: Started Session 5 of user porridge. mar 02 22:39:07 debian systemd-logind[465]: Session c2 logged out. Waiting for processes to exit. mar 02 22:39:10 debian porridge[9464]: gnome-starting-screenlock mar 02 22:39:24 debian porridge[9739]: gnome-attempting-unlock mar 02 22:39:27 debian porridge[10824]: gnome-stuck mar 02 22:39:29 debian porridge[10831]: ssh-logging-out mar 02 22:39:30 debian systemd-logind[465]: Session 2 logged out. Waiting for processes to exit. mar 02 22:39:36 debian systemd[1]: Started Session 6 of user porridge. To summarize the above: - c1 is the gdm session where I log into cinnamon - 2 is my ssh session for calling logger - 4 is the cinnamon X session - c2 is the gdm session where I log into GNOME - 5 is the GNOME session - 6 is another ssh login, irrelevant And now it's pretty clear that indeed gnome-shell for some reason thinks it belongs to session 4, while it's part of session 5. $ grep NoSuchSession journal3.txt mar 02 22:39:05 debian gnome-shell[7965]: JS ERROR: Could not get a proxy for the current session: Gio.IOErrorEnum: GDBus.Error:org.freedesktop.login1.NoSuchSession: No session '4' known In fact, session 4 is reported to be gone for good 4 seconds before I even press ENTER after the password to log into GNOME: mar 02 22:38:57 debian systemd-logind[465]: Removed session 4. mar 02 22:39:02 debian porridge[7905]: gnome-starting-login Now back to your questions from the previous time: > 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, Sorry, I didn't record the times, but yes, they should be the last two sessions in this order. > 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 > @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?) > There are two GNOME session types in the menu. I believe the one called just "GNOME" is indeed Wayland-based. 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? > If you mean a message such as "gdm-password][PID]: gkr-pam: unlocked login keyring" then yes, this appears exactly when I press enter after entering the password in the screen unlock dialog. 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 > Here's the effect: porridge@debian:~$ sudo loginctl SESSION UID USER SEAT TTY 5 1000 porridge seat0 tty3 6 1000 porridge pts/0 2 sessions listed. porridge@debian:~$ grep NoSuchSession journal3.txt mar 02 22:39:05 debian gnome-shell[7965]: JS ERROR: Could not get a proxy for the current session: Gio.IOErrorEnum: GDBus.Error:org.freedesktop.login1.NoSuchSession: No session '4' known porridge@debian:~$ sudo loginctl unlock-session 4 Failed to issue method call: No session '4' known porridge@debian:~$ sudo loginctl unlock-session 5 porridge@debian:~$ Nothing (apart from sudo) gets logged to journal when I run these unlock-session commands. Neither is there any effect in the GUI. Still locked out. > 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. > Just to be sure I also tried with session 6 (my ssh login) but that didn't help either :-) I'd be curious to learn what mechanism gnome-shell used that gets fooled into thinking it's another session. And why not just getenv("XDG_SESSION_ID")? Marcin