You are not logged in.

#1 2021-03-31 23:50:31

paragordius
Member
Registered: 2017-07-12
Posts: 12

[SOLVED] lightdm hangs for 90 seconds after authenticating

Just ran `pacman -Syu` today for the first time in a few weeks. After a reboot, lightdm came up like normal and I entered my password, followed by the enter key. Then lightdm just hangs for 90 seconds before starting i3. After it starts, my session is a little odd. I have transparency set normally for kitty, but the window is totally transparent. If I exit i3 and log back in, it's instant and everything is working like normal. The only sign of anything wrong I can find is in the systemd logs relates to `session-c1.scope`:

Mar 31 19:28:43 d0g systemd[734]: Started Virtual filesystem service.
Mar 31 19:28:43 d0g NetworkManager[604]: <info>  [1617233323.3943] manager: NetworkManager state is now CONNECTED_GLOBAL
Mar 31 19:28:43 d0g lightdm[615]: [+3.57s] DEBUG: Greeter connected version=1.30.0 api=1 resettable=false
Mar 31 19:28:43 d0g polkitd[661]: <no filename>:3: action=[Action id='org.freedesktop.DisplayManager.AccountsService.ReadAny']
Mar 31 19:28:43 d0g polkitd[661]: <no filename>:4: subject=[Subject pid=742 user='lightdm' groups=lightdm seat='seat0' session='c1' local=true active=true]
Mar 31 19:28:43 d0g polkitd[661]: <no filename>:3: action=[Action id='org.freedesktop.DisplayManager.AccountsService.ReadAny']
Mar 31 19:28:43 d0g polkitd[661]: <no filename>:4: subject=[Subject pid=742 user='lightdm' groups=lightdm seat='seat0' session='c1' local=true active=true]
Mar 31 19:28:43 d0g lightdm[615]: [+3.77s] DEBUG: Greeter start authentication for paragordius
Mar 31 19:28:43 d0g lightdm[615]: [+3.77s] DEBUG: Session pid=773: Started with service 'lightdm', username 'paragordius'
Mar 31 19:28:43 d0g at-spi-bus-launcher[752]: dbus-daemon[752]: Activating service name='org.a11y.atspi.Registry' requested by ':1.0' (uid=620 pid=742 comm="/usr/bin/lightdm-gtk-greeter ")
Mar 31 19:28:43 d0g lightdm[615]: [+3.77s] DEBUG: Session pid=773: Got 1 message(s) from PAM
Mar 31 19:28:43 d0g lightdm[615]: [+3.77s] DEBUG: Prompt greeter with 1 message(s)
Mar 31 19:28:43 d0g at-spi-bus-launcher[752]: dbus-daemon[752]: Successfully activated service 'org.a11y.atspi.Registry'
Mar 31 19:28:43 d0g at-spi-bus-launcher[775]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Mar 31 19:28:45 d0g systemd[1]: systemd-rfkill.service: Succeeded.
Mar 31 19:28:45 d0g audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 31 19:28:47 d0g lightdm[615]: [+7.93s] DEBUG: Continue authentication
Mar 31 19:28:47 d0g lightdm[773]: gkr-pam: unable to locate daemon control file
Mar 31 19:28:47 d0g lightdm[773]: gkr-pam: stashed password to try later in open session
Mar 31 19:28:47 d0g audit[773]: USER_AUTH pid=773 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:authentication grantors=pam_shells,pam_faillock,pam_permit,pam_faillock,pam_gnome_keyring acct="paragordius" exe="/usr/bin/lightdm" hostname=? addr=? terminal=:0 res=success'
Mar 31 19:28:47 d0g dbus-daemon[603]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.18' (uid=0 pid=773 comm="lightdm --session-child 12 19 ")
Mar 31 19:28:47 d0g dbus-daemon[603]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
Mar 31 19:28:47 d0g lightdm[773]: pam_systemd_home(lightdm:account): systemd-homed is not available: Unit dbus-org.freedesktop.home1.service not found.
Mar 31 19:28:47 d0g audit[773]: USER_ACCT pid=773 uid=0 auid=4294967295 ses=4294967295 msg='op=PAM:accounting grantors=pam_access,pam_unix,pam_permit,pam_time acct="paragordius" exe="/usr/bin/lightdm" hostname=? addr=? terminal=:0 res=success'
Mar 31 19:28:47 d0g lightdm[615]: [+7.95s] DEBUG: Session pid=773: Authentication complete with return value 0: Success
Mar 31 19:28:47 d0g lightdm[615]: [+7.95s] DEBUG: Authenticate result for user paragordius: Success
Mar 31 19:28:47 d0g lightdm[615]: [+7.95s] DEBUG: User paragordius authorized
Mar 31 19:28:47 d0g lightdm[615]: [+7.95s] DEBUG: Greeter sets language en_US.utf8
Mar 31 19:28:47 d0g lightdm[615]: [+7.98s] DEBUG: Greeter requests session i3
Mar 31 19:28:47 d0g lightdm[615]: [+7.98s] DEBUG: Seat seat0: Stopping greeter; display server will be re-used for user session
Mar 31 19:28:47 d0g lightdm[615]: [+7.98s] DEBUG: Terminating login1 session c1
Mar 31 19:28:47 d0g systemd[1]: Stopping Session c1 of user lightdm.
Mar 31 19:28:47 d0g lightdm[615]: [+7.99s] DEBUG: Session pid=730: Sending SIGTERM
Mar 31 19:28:50 d0g systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Mar 31 19:28:50 d0g audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 31 19:28:50 d0g kernel: kauditd_printk_skb: 7 callbacks suppressed
Mar 31 19:28:50 d0g kernel: audit: type=1131 audit(1617233330.393:53): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 31 19:29:38 d0g systemd-timesyncd[594]: Initial synchronization to time server 162.159.200.123:123 (2.arch.pool.ntp.org).
Mar 31 19:29:38 d0g systemd[1]: systemd-hostnamed.service: Succeeded.
Mar 31 19:29:38 d0g audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 31 19:29:38 d0g kernel: audit: type=1131 audit(1617233378.792:54): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 31 19:29:38 d0g audit: BPF prog-id=18 op=UNLOAD
Mar 31 19:29:38 d0g kernel: audit: type=1334 audit(1617233378.851:55): prog-id=18 op=UNLOAD
Mar 31 19:29:38 d0g kernel: audit: type=1334 audit(1617233378.851:56): prog-id=17 op=UNLOAD
Mar 31 19:29:38 d0g audit: BPF prog-id=17 op=UNLOAD
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Stopping timed out. Killing.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 730 (lightdm) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 742 (lightdm-gtk-gre) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 731 (gmain) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 732 (gdbus) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 743 (gmain) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 753 (gdbus) with signal SIGKILL.

Which leads me to:

 $ sudo journalctl -u session-c1.scope -b
-- Journal begins at Fri 2020-11-06 18:14:49 EST, ends at Wed 2021-03-31 19:41:03 EDT. --
Mar 31 19:28:42 d0g systemd[1]: Started Session c1 of user lightdm.
Mar 31 19:28:47 d0g systemd[1]: Stopping Session c1 of user lightdm.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Stopping timed out. Killing.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 730 (lightdm) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 742 (lightdm-gtk-gre) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 731 (gmain) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 732 (gdbus) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 743 (gmain) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Killing process 753 (gdbus) with signal SIGKILL.
Mar 31 19:30:46 d0g systemd[1]: session-c1.scope: Failed with result 'timeout'.
Mar 31 19:30:46 d0g systemd[1]: Stopped Session c1 of user lightdm.

Where can I find out what's causing the 90 second hang?

Last edited by paragordius (2021-04-02 14:37:45)

Offline

#2 2021-04-01 05:45:07

seth
Member
Registered: 2012-09-03
Posts: 49,986

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

session journal?

Since there have been recently several reports about flatpak/portal acting up w/ gtk programs:

pacman -Qs '(flatpak|portal)'

Also your i3 config and whether the same happend for eg. an openbox session.

Online

#3 2021-04-01 14:10:46

paragordius
Member
Registered: 2017-07-12
Posts: 12

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

seth wrote:

session journal?

Where do I go to find a more in depth log of my session?

As far as flatpak/portal, I do have it installed, but removing them and rebooting showed the same behavior.

$ pacman -Qs '(flatpak|portal)'
local/flatpak 1.10.2-1
    Linux application sandboxing and distribution framework (formerly xdg-app)
local/xdg-desktop-portal 1.8.0-1
    Desktop integration portals for sandboxed apps
local/xdg-desktop-portal-gtk 1.8.0-1
    A GTK+ backend for xdg-desktop-portal

Openbox has the same behavior as i3, so I don't think that's the culprit.

Edit: for the sake of completeness, here's my i3 config: http://ix.io/2UJz

Last edited by paragordius (2021-04-01 14:14:34)

Offline

#4 2021-04-01 14:23:58

seth
Member
Registered: 2012-09-03
Posts: 49,986

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

journalctl, /var/log/lightdm, ~/.xsession-errors

Since it's apparently not the session, can you start i3 via xinit w/o delay?

Online

#5 2021-04-01 16:14:50

paragordius
Member
Registered: 2017-07-12
Posts: 12

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

It's been a long time since I went without a login manager (pre-systemd for sure), so I'm not sure I normally need to switch to another VT after systemd finishes, but once I do, I can `startx` and it works as expected and without delay.

Here is a tarball of my systemd logs with debug on: http://ix.io/2UKf

Edit: So I fixed my problem. It seems I was having the lightdm fast boot issue: https://wiki.archlinux.org/index.php/Li … TTY_output

Uncommenting the line in my ligghtdm.conf file mentioned in the wiki has my login times back to normal (nearly instant). It's worth noting that I was not experiencing the symptoms mentioned in the article (no display or TTY only), but it fixed it nonetheless.

Last edited by paragordius (2021-04-01 16:41:57)

Offline

#6 2021-04-01 20:11:06

seth
Member
Registered: 2012-09-03
Posts: 49,986

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

Is it also fixed by https://wiki.archlinux.org/index.php/Ke … _KMS_start instead of the lightdm config change?

Online

#7 2021-04-01 23:05:48

paragordius
Member
Registered: 2017-07-12
Posts: 12

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

That works! That makes sense that it's a modesetting thing.

Offline

#8 2021-04-02 06:00:22

seth
Member
Registered: 2012-09-03
Posts: 49,986

Re: [SOLVED] lightdm hangs for 90 seconds after authenticating

Please always remember to mark resolved threads by editing your initial posts subject - so others will know that there's no task left, but maybe a solution to find.
Thanks.

Online

Board footer

Powered by FluxBB