#898092 sddm: takes extremely long time to start

Package:
src:qtbase-opensource-src
Source:
qtbase-opensource-src
Submitter:
Leandro Doctors
Date:
2021-05-24 17:21:09 UTC
Severity:
important
Tags:
#898092#5
Date:
2018-05-07 03:12:34 UTC
From:
To:
Dear Maintainer,

*** Reporter, please consider answering these questions, where appropriate
***

    * What led up to the situation?

Intalling Plasma Desktop after having problems with several GTK-based
Desktop Environments (may fill bug on that once this one is solved).

    * What exactly did you do (or not do) that was effective (or
      ineffective)?

For now, just started to do some debugging... (I copy the output of
relevant systemd-related commands below.)

It looks as if the program was spending those three minutes trying to find
something else, and it starts only after that time.


    * What was the outcome of this action?

SSDM takes three (3!) minutes to initialize.


    * What outcome did you expect instead?

SSDM to take a couple of seconds to initialize.


Here is the output of relevant systemd-related commands


  * The service seems to be OK...

root@berlin:/home/allentiak# systemctl status sddm.service
● sddm.service - Simple Desktop Display Manager
    Loaded: loaded (/lib/systemd/system/sddm.service; indirect; vendor
preset: enabled)
    Active: active (running) since Sun 2018-05-06 23:33:07 -03; 8min ago
      Docs: man:sddm(1)
            man:sddm.conf(5)
  Main PID: 685 (sddm)
     Tasks: 4 (limit: 4915)
    Memory: 199.6M
    CGroup: /system.slice/sddm.service
            ├─685 /usr/bin/sddm
            └─783 /usr/lib/xorg/Xorg -nolisten tcp -auth
/var/run/sddm/{60ab4bb8-66a7-463a-a7cf-3241d7bd2e6c} -back

May 06 23:39:16 berlin sddm-helper[1031]: [PAM] returning.
May 06 23:39:16 berlin sddm[685]: Authenticated successfully
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:setcred):
pam_kwallet5: pam_sm_setcred
May 06 23:39:16 berlin sddm-helper[1031]: pam_unix(sddm:session): session
opened for user allentiak by (uid=0)
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:session):
pam_kwallet5: pam_sm_open_session
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:session):
pam_kwallet5: final socket path: /run/user/1
May 06 23:39:16 berlin sddm-helper[1031]: Starting: "/etc/sddm/Xsession
\"/usr/bin/startkde\""
May 06 23:39:16 berlin sddm[685]: Session started
May 06 23:39:16 berlin sddm[685]: Auth: sddm-helper exited successfully
May 06 23:39:16 berlin sddm[685]: Greeter stopped.


  * ...But it took it (3 minutes!) to start.


root@berlin:/home/allentiak# journalctl -rx --unit=sddm.service
-- Logs begin at Sun 2018-05-06 23:33:05 -03, end at Sun 2018-05-06
23:41:05 -03. --
May 06 23:39:16 berlin sddm[685]: Greeter stopped.
May 06 23:39:16 berlin sddm[685]: Auth: sddm-helper exited successfully
May 06 23:39:16 berlin sddm[685]: Session started
May 06 23:39:16 berlin sddm-helper[1031]: Starting: "/etc/sddm/Xsession
\"/usr/bin/startkde\""
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:session):
pam_kwallet5: final socket path: /run/user/1
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:session):
pam_kwallet5: pam_sm_open_session
May 06 23:39:16 berlin sddm-helper[1031]: pam_unix(sddm:session): session
opened for user allentiak by (uid=0)
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:setcred):
pam_kwallet5: pam_sm_setcred
May 06 23:39:16 berlin sddm[685]: Authenticated successfully
May 06 23:39:16 berlin sddm-helper[1031]: [PAM] returning.
May 06 23:39:16 berlin sddm-helper[1031]: pam_kwallet5(sddm:auth): (null):
pam_sm_authenticate
May 06 23:39:16 berlin sddm-helper[1031]: [PAM] Conversation with 1 messages
May 06 23:39:16 berlin sddm-helper[1031]: [PAM] Preparing to converse...
May 06 23:39:16 berlin sddm-helper[1031]: [PAM] Authenticating...
May 06 23:39:16 berlin sddm-helper[1031]: [PAM] Starting...
May 06 23:39:16 berlin sddm[685]: Session
"/usr/share/xsessions/plasma.desktop" selected, command: "/usr/bin/start
May 06 23:39:16 berlin sddm[685]: Reading from
"/usr/share/xsessions/plasma.desktop"
May 06 23:39:16 berlin sddm[685]: Reading from
"/usr/share/xsessions/plasma.desktop"

* look here

May 06 23:39:16 berlin sddm[685]: Message received from greeter: Login
May 06 23:36:52 berlin sddm[685]: Message received from greeter: Connect
May 06 23:36:52 berlin sddm[685]: Greeter session started successfully
May 06 23:36:52 berlin sddm-helper[792]: pam_unix(sddm-greeter:session):
session opened for user sddm by (uid=0)
May 06 23:36:52 berlin sddm-helper[792]: [PAM] returning.
May 06 23:36:52 berlin sddm-helper[792]: [PAM] Authenticating...
May 06 23:36:52 berlin sddm-helper[792]: [PAM] Starting...

#898092#10
Date:
2018-05-07 04:27:55 UTC
From:
To:
By the way: lightdm works fine.
(gdm3 does not work at all, but I cannot debug everything at the same time)

#898092#15
Date:
2018-05-07 07:43:25 UTC
From:
To:
¡Hola Leandro!

El 2018-05-07 a las 03:12 +0000, Leandro Doctors escribió:

It seems that there is a reported bug on 4.16.0 about this:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=898021

You might want to downgrade to 4.15.0 just to be sure that you a are affected
by the same issue.

Happy hacking,

#898092#22
Date:
2018-05-07 15:45:19 UTC
From:
To:
Thanks a lot, Maximiliano! That was it!

Leandro

Duplicates #898021.

#898092#27
Date:
2018-05-07 16:47:15 UTC
From:
To:
merges 898021.
#898092#34
Date:
2018-07-20 10:53:03 UTC
From:
To:
sddm is making a blocking call to getrandom(), via the glibc function
getentropy(), via the QRandomGenerator class. Here's a backtrace:

#0  0x00007ffff5ef303a in getentropy (buffer=0x7fffffffe9dc,
    length=<optimized out>) at ../sysdeps/unix/sysv/linux/getentropy.c:45
#1  0x00007ffff68a2beb in ?? ()
   from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#2  0x00007ffff68a3538 in QHashData::detach_helper(void (*)(QHashData::Node*, void*), void (*)(QHashData::Node*), int, int) ()
   from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#3  0x00007ffff69af7c1 in ?? ()
   from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#4  0x00007ffff69aef3b in QLoggingCategory::defaultCategory() ()
   from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#5  0x00007ffff683d815 in qt_message_output(QtMsgType, QMessageLogContext const&, QString const&) () from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#6  0x00007ffff693bf70 in QDebug::~QDebug() ()
   from target:/usr/lib/x86_64-linux-gnu/libQt5Core.so.5
#7  0x000055555559c870 in SDDM::DaemonApp::DaemonApp(int&, char**) ()
#8  0x000055555557d1c6 in main ()

Reassigning this to Qt as it is not safe to use these functions in a
general-purpose library for Linux.  They should only be used if it's
acceptable to wait some time for entropy to be available.

Ben.

#898092#49
Date:
2018-07-20 13:19:25 UTC
From:
To:
Hi Ben!

El viernes, 20 de julio de 2018 07:53:03 -03 Ben Hutchings escribió:

Thanks *a lot* for the analysis. I have checked the SDDM and Qt code and
indeed it seems a bug in Qt, as QRandomGenerator is used in QHash. However it
might be a bug because according to the doc it should detect this cases and
fall back to pseudo-random generators.

All in all, thanks again for pointing this.

#898092#56
Date:
2018-07-20 13:36:18 UTC
From:
To:
Maxy (KDE/sddm maintainer) just suggested me to use haveged to workaround the
issue.

From the Qt/sddm code this would certainly not affect security, as the problem
lies in a hash structure used in the code. I can not vouch for other stuff in
the machine.

I have not seen this bug so far, but if any of you can still reproduce it you
might want to give this a try.

Cheers, Lisandro.

#898092#61
Date:
2018-07-20 15:44:02 UTC
From:
To:
Upstream bug report has been marked as "Out of scope".

So what now, libqt5core5 package must depend on haveged? :)

(or Qt recompiled without getentropy() ?)

#898092#66
Date:
2018-07-20 16:24:30 UTC
From:
To:
Upstream has just said that they do not consider this a bug: the device needs
to have entropy.

So for sddm I see one workaround and one solution:

Workaround: use haveged.

"Fix": make sddm upstreams consider not using QHash.

An interesting point is that QHash has a long history inside Debian, and so
far this is the only place where this situation has arised. That's probably
because once the user has logged in there might be enough entropy for it to
work.

Regards, Lisandro.

#898092#73
Date:
2018-07-20 16:42:24 UTC
From:
To:
El viernes, 20 de julio de 2018 12:44:02 -03 Vincas Dargis escribió:

None of the above will happen, at most QtCore might recommend haveged.

The fact that this has only happened in sddm marks that this is very specific
to boot time. So a solution can be making sddm not use QHash.

#898092#78
Date:
2018-07-20 16:59:13 UTC
From:
To:
El viernes, 20 de julio de 2018 13:42:24 -03 Lisandro Damián Nicanor Pérez
Meyer escribió:
[snip]

I think this might probe difficult. sddm uses QHash in some places, but if it
uses logging then I see no way around but to get entropy.

#898092#83
Date:
2018-07-23 13:30:06 UTC
From:
To:
This has happened so far:

From the Debian side maxy added haveged as a sddm recommendation and as a
workaround.

From the Qt side Thiago from upstream is trying to determine what changed in
the kernel side, as this clearly started to happen with 4.16 and got worse
with 4.17.

Ben, linux maintainers: if you could give us a hand to determine what changed
from the kernel side it would be much much appreciated. If we find that there
are valid changes then we might have an opportunity to make Qt upstreams
reconsider the issue.

Cheers, Lisandro.

#898092#88
Date:
2018-07-23 15:48:56 UTC
From:
To:
CVE-2018-1108 was fixed in the kernel.

Ben.

#898092#93
Date:
2018-07-23 15:51:09 UTC
From:
To:
Thanks Ben!!!!
#898092#100
Date:
2018-07-27 16:52:26 UTC
From:
To:
Should it better recommend rng-tools5? It's a better quality entropy generator that's
more suitable especially for hardware with rdrand CPU feature or TPM module.

Regards,
Hillel.