Bug 466193 - Plasmashell sometimes tries to load before kactivitymanagerd has finished loading, and fails
Summary: Plasmashell sometimes tries to load before kactivitymanagerd has finished loa...
Status: RESOLVED FIXED
Alias: None
Product: plasmashell
Classification: Plasma
Component: Startup process (show other bugs)
Version: 6.1.4
Platform: Gentoo Packages Linux
: HI major
Target Milestone: 1.0
Assignee: Plasma Bugs List
URL:
Keywords:
: 466918 468627 493303 (view as bug list)
Depends on:
Blocks:
 
Reported: 2023-02-21 13:10 UTC by Erik Quaeghebeur
Modified: 2024-10-01 15:28 UTC (History)
9 users (show)

See Also:
Latest Commit:
Version Fixed In: 6.2.0
Sentry Crash Report:


Attachments
Journal output until and including issue (134.98 KB, text/plain)
2023-03-04 11:08 UTC, Erik Quaeghebeur
Details
Log when shell failed to load (36.21 KB, text/plain)
2023-07-14 23:00 UTC, guimarcalsilva
Details
Known good boot (60.58 KB, text/plain)
2023-07-14 23:01 UTC, guimarcalsilva
Details
failed wayland autologin logs (272.79 KB, text/plain)
2024-08-13 19:47 UTC, mpeter.68m0y
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Erik Quaeghebeur 2023-02-21 13:10:10 UTC
SUMMARY
Since updating KDE Frameworks from 5.99.0 to 5.102.0 and after rebooting, my panel is gone. I re-created the panel, but after the next boot, it is gone again. This is quite bothersome. I cannot keep on recreating the panel every time, certainly because I do modify it quite a bit from the default.

STEPS TO REPRODUCE
1. KDE Frameworks from 5.99.0 to 5.102.0 
2. Reboot

OBSERVED RESULT
No panel

EXPECTED RESULT
Panel

SOFTWARE/OS VERSIONS
KDE Plasma Version: 5.26.5
KDE Frameworks Version: 5.102.0
Qt Version: 5.15.8

ADDITIONAL INFORMATION
It may be that starting a new session is enough to trigger the issue. But I have not tried that yet.

Plasma-related entries in my logs:
---
plasmashell[1162]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
plasmashell[1162]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
[…]
plasmashell[1162]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
plasmashell[1162]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
[…]
plasmashell[1162]: kf.plasma.quick: Applet preload policy set to 1
[…]
plasmashell[1162]: org.kde.plasma.containmentlayoutmanager: Error: cannot change the containment to AppletsLayout
---
Here, all but the 5th line are at the error level. The fifth line is at the info level.
Comment 1 Nate Graham 2023-02-21 22:55:44 UTC
> plasmashell[1162]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
This indicates that your system is broken, so Plasma doesn't load properly. kactivitymanagerd needs to be running. Any idea why it might not be?
Comment 2 Erik Quaeghebeur 2023-02-22 09:04:04 UTC
(In reply to Nate Graham from comment #1)
> > plasmashell[1162]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
> This indicates that your system is broken, so Plasma doesn't load properly.
> kactivitymanagerd needs to be running. Any idea why it might not be?

I looked a bit broader and kactivitymanagerd is running:
---
dbus-daemon[1035]: [session uid=1000 pid=1035] Activating via systemd: service name='org.kde.ActivityManager' unit='plasma-kactivitymanagerd.service' requested by ':1.14' (uid=1000 pid…
…
systemd[1013]: Starting plasma-kactivitymanagerd.service...
…
plasmashell[1131]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
plasmashell[1131]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
…
dbus-daemon[1035]: [session uid=1000 pid=1035] Successfully activated service 'org.kde.ActivityManager'
systemd[1013]: Started plasma-kactivitymanagerd.service.
plasmashell[1131]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
plasmashell[1131]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
---
So the first seems to be a race condition: plasmashell expects kactivitymanagerd to be ready while it is still loading. I guess the second time the warning is logged may also be a race condition, but then with output arriving in the log once it has already been resolved (this is all happening within the same second).

So it seems that plasmashell should explicitly be told to wait for kactivitymanagerd to be loaded, which is likely another bug.
Comment 3 Nate Graham 2023-02-22 20:40:29 UTC
Hmm, kactivitymanagerd's service file has this in it:

Before=graphical-session.target
Comment 4 Erik Quaeghebeur 2023-02-26 20:56:07 UTC
(In reply to Nate Graham from comment #3)
> Hmm, kactivitymanagerd's service file has this in it:
> 
> Before=graphical-session.target

But is graphical-session.target the one that matters here? I have the feeling it is not.

In the log, I see
---
systemd[1128]: Starting plasma-kactivitymanagerd.service...
systemd[1128]: Started plasma-plasmashell.service.
---
So plasmashell is started essentially concurrently with kactivitymanagerd.

This is not strange, as we can see from their unit sections in their service files:

---plasma-plasmashell.service---
[Unit]
Description=KDE Plasma Workspace
After=plasma-ksmserver.service plasma-kcminit.service
PartOf=graphical-session.target
---
---plasma-kactivitymanagerd.service---
[Unit]
Description=KActivityManager Activity manager Service
PartOf=graphical-session.target
Before=graphical-session.target
---

So AFAIU, in plasma-plasmashell.service, we should have the following as the ‘After’ line:
---
After=plasma-ksmserver.service plasma-kcminit.service plasma-kactivitymanagerd.service
---
Comment 5 Nate Graham 2023-02-27 17:01:47 UTC
Cool, feel free to submit a patch!
Comment 6 David Edmundson 2023-03-03 10:22:45 UTC
Don't make a patch doing that.
Blocking plasma from starting until KAMD is fully up would make everything slower and is missing some key parts of the story.

KActivityManager daemon is DBus activated. Plasmashell will make a call to kamd track progress that way.  It does it internally, that's why we don't have a strict systemd dependency. 

we can see someone doing that here:

>dbus-daemon[1035]: [session uid=1000 pid=1035] Activating via systemd: service name='org.kde.ActivityManager' unit='plasma-kactivitymanagerd.service' requested by ':1.14' (uid=1000 pid…

dbus-daemon should keep track of that all things and let plasmashell know which has it's own tracking. If we get in to the error path listed it means we've been told that starting 

If you get the error listed it means plasmashell explicitly thinks kamd failed to start rather than a race. Can you attach the non-abridged logs.
Comment 7 Erik Quaeghebeur 2023-03-04 11:08:57 UTC
Created attachment 156989 [details]
Journal output until and including issue

(In reply to David Edmundson from comment #6)
> 
> If you get the error listed it means plasmashell explicitly thinks kamd failed to start rather than a race. Can you attach the non-abridged logs.

These are the non-abridged logs up until and including the issue.
Comment 8 Bug Janitor Service 2023-03-19 03:45:41 UTC
Dear Bug Submitter,

This bug has been in NEEDSINFO status with no change for at least
15 days. Please provide the requested information as soon as
possible and set the bug status as REPORTED. Due to regular bug
tracker maintenance, if the bug is still in NEEDSINFO status with
no change in 30 days the bug will be closed as RESOLVED > WORKSFORME
due to lack of needed information.

For more information about our bug triaging procedures please read the
wiki located here:
https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging

If you have already provided the requested information, please
mark the bug as REPORTED so that the KDE team knows that the bug is
ready to be confirmed.

Thank you for helping us make KDE software even better for everyone!
Comment 9 Simon Vogl 2023-03-19 13:27:45 UTC
(In reply to Bug Janitor Service from comment #8)
> Dear Bug Submitter,
> 
> This bug has been in NEEDSINFO status with no change for at least
> 15 days. Please provide the requested information as soon as
> possible and set the bug status as REPORTED. Due to regular bug
> tracker maintenance, if the bug is still in NEEDSINFO status with
> no change in 30 days the bug will be closed as RESOLVED > WORKSFORME
> due to lack of needed information.
> 
> For more information about our bug triaging procedures please read the
> wiki located here:
> https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging
> 
> If you have already provided the requested information, please
> mark the bug as REPORTED so that the KDE team knows that the bug is
> ready to be confirmed.
> 
> Thank you for helping us make KDE software even better for everyone!

I think the requested info has already been provided, should we change back the status to "Reported"?
Comment 10 Nate Graham 2023-04-09 22:28:08 UTC
Relevant log bits:

09:46:36 PCNAME dbus-daemon[1040]: [session uid=1000 pid=1040] Activating via systemd: service name='org.kde.ActivityManager' unit='plasma-kactivitymanagerd.service' requested by ':1.14' (uid=1000 pid=1133 comm="/usr/bin/plasmashell --no-respawn")

...

09:46:36 PCNAME systemd[1018]: Started plasma-plasmashell.service.

...

09:46:36 PCNAME plasmashell[1133]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.

...

09:46:36 PCNAME dbus-daemon[1040]: [session uid=1000 pid=1040] Successfully activated service 'org.kde.ActivityManager'
09:46:36 PCNAME systemd[1018]: Started plasma-kactivitymanagerd.service.
09:46:36 PCNAME plasmashell[1133]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.




This sequence of events suggests that plasmashell is trying to load before kamd has finished.
Comment 11 Nate Graham 2023-04-10 03:15:41 UTC
*** Bug 466918 has been marked as a duplicate of this bug. ***
Comment 12 Nate Graham 2023-05-17 14:50:26 UTC
*** Bug 468627 has been marked as a duplicate of this bug. ***
Comment 13 David Edmundson 2023-06-02 13:04:34 UTC
>This sequence of events suggests that plasmashell is trying to load before kamd has finished.

That's not the full story. 

Plasmashell will try to start kamd internally (via DBus activation) and only proceed when that gets a reply/failure to our original call.
We need to work out what that call fails.
Comment 14 guimarcalsilva 2023-07-14 22:47:25 UTC
I noticed BUG 466918 was marked as a duplicate of this, which is very similar to what's happening to me, however there they said it happens consistently, while in my case it happens intermittently. This week Plasma (5.27.6) failed to load twice after starting up the computer (I see the wallpaper and the mouse cursor, but the shell never loads). Restarting the computer fixes the issue and it happens seemingly randomly. I noticed my logs show the same message "Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.", however, I checked 3 other successful boots and they also show the same message twice, even though the shell loads succefully. I also don't have any problems with the panel disappearing.

I also tested my Plasma 6 VM and it shows the same message as well after a successful boot.

Can someone confirm the same message also appears after a successful boot? Maybe the issue is something else entirely.
Comment 15 Simon Vogl 2023-07-14 22:53:38 UTC
(In reply to guimarcalsilva from comment #14)
> I noticed BUG 466918 was marked as a duplicate of this, which is very
> similar to what's happening to me, however there they said it happens
> consistently, while in my case it happens intermittently. This week Plasma
> (5.27.6) failed to load twice after starting up the computer (I see the
> wallpaper and the mouse cursor, but the shell never loads). Restarting the
> computer fixes the issue and it happens seemingly randomly. I noticed my
> logs show the same message "Aborting shell load: The activity manager daemon
> (kactivitymanagerd) is not running.", however, I checked 3 other successful
> boots and they also show the same message twice, even though the shell loads
> succefully. I also don't have any problems with the panel disappearing.
> 
> I also tested my Plasma 6 VM and it shows the same message as well after a
> successful boot.
> 
> Can someone confirm the same message also appears after a successful boot?
> Maybe the issue is something else entirely.

I can confirm this, 100% identical behaviour on my system. Also appears after a successful boot, and only very occasionally the shell actually fails to load.
Comment 16 guimarcalsilva 2023-07-14 23:00:37 UTC
Created attachment 160293 [details]
Log when shell failed to load

PS: I deleted the last few lines where I switched TTYs and tried to kill plasmashell with killall since that's probably not useful.
Comment 17 guimarcalsilva 2023-07-14 23:01:40 UTC
Created attachment 160294 [details]
Known good boot

Known good boot - Shows the same message
Comment 18 Nate Graham 2023-08-22 21:56:20 UTC
*** Bug 473514 has been marked as a duplicate of this bug. ***
Comment 19 mpeter.68m0y 2024-08-13 19:47:15 UTC
Created attachment 172596 [details]
failed wayland autologin logs

I can reliably reproduce this on openSUSE Leap 15.6 with Plasma 5.27.11, when autlogin is enabled with the wayland session.
I was able to login wo the wayland session normally, at least for the few times I tried it.

It started after the first time I tried out if hybrid sleep is working, which I have set it up in the power management menu of the KDE control panel. The hybrid part of it did not, while hibernation by itself works, but thats a different ticket.

This is a fairly new installation. It was installed with this exact leap version a few weeks ago.

I have attached logs from such an unsuccessful boot.
Comment 20 Erik Quaeghebeur 2024-09-08 13:29:47 UTC
Still an issue with Plasma 6.1.4.
Comment 21 homem.gustavo 2024-09-17 11:28:02 UTC
This is happening with fully updated Kubuntu 24.04.
Comment 22 homem.gustavo 2024-09-17 11:30:02 UTC
Sep 17 13:21:42 gh-xps-2404 systemd[1706]: Starting plasma-plasmashell.service - KDE Plasma Workspace...
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: Checking screens: available: (QScreen(0x62ff42ac6640, name="eDP-1"), QScreen(0x62ff42ac6730, name="DP-2-1")) redundant: QHash() fake: QSet() all: (QScreen(0x62ff42ac6640, name="eDP-1"), QScreen(0x62ff42ac6730, name="DP-2-1"))
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: Checking screens: available: (QScreen(0x62ff42ac6640, name="eDP-1"), QScreen(0x62ff42ac6730, name="DP-2-1")) redundant: QHash() fake: QSet() all: (QScreen(0x62ff42ac6640, name="eDP-1"), QScreen(0x62ff42ac6730, name="DP-2-1"))
Sep 17 13:21:42 gh-xps-2404 systemd[1706]: Started plasma-plasmashell.service - KDE Plasma Workspace.
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: Aborting shell load: The activity manager daemon (kactivitymanagerd) is not running.
Logs from journalctl:

Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: If this Plasma has been installed into a custom prefix, verify that its D-Bus services dir is known to the system for the daemon to be activatable.
Sep 17 13:21:42 gh-xps-2404 plasmashell[1990]: kf.plasma.quick: Applet preload policy set to 1
Sep 17 13:21:43 gh-xps-2404 plasmashell[1990]: file:///usr/lib/x86_64-linux-gnu/qt5/qml/org/kde/kirigami.2/templates/InlineMessage.qml:265:13: QML SelectableLabel: Binding loop detected for property "implicitWidth"
Sep 17 13:21:43 gh-xps-2404 plasmashell[1990]: file:///usr/lib/x86_64-linux-gnu/qt5/qml/org/kde/kirigami.2/templates/InlineMessage.qml:265:13: QML SelectableLabel: Binding loop detected for property "implicitWidth"
Sep 17 13:21:43 gh-xps-2404 plasmashell[1990]: Checking screens: available: (QScreen(0x62ff42ac6730, name="DP-2-1"), QScreen(0x62ff42ac6640, name="eDP-1")) redundant: QHash() fake: QSet() all: (QScreen(0x62ff42ac6730, name="DP-2-1"), QScreen(0x62ff42ac6640, name="eDP-1"))

Launching manually with

plasmashell --replace

always results in the desktop being loaded.
Comment 23 homem.gustavo 2024-09-17 12:12:39 UTC
Workaround:

1. sudo mv /usr/bin/plasmashell /usr/bin/plasmashell.bin
2. sudo ln -s /usr/local/bin/plasmashell-wait.sh /usr/bin/plasmashell
3. create /usr/local/bin/plasmashell-wait.sh as follows

```
#!/bin/bash

# Note: you can review the logs by running as logged in user
# journalctl --user-unit=plasma-plasmashell.service --boot 0
# ref: https://bugs.kde.org/show_bug.cgi?id=466193

DELAY=1
EXTRA_DELAY=5 # fine tune this value until it is reliable on your system

PROCNAME=kactivitymanagerd
BINNAME=/usr/bin/plasmashell.bin

while true; do
    pgrep -f $PROCNAME -u $USER &> /dev/null
    if [ $? -eq 0 ]; then
        echo "$PROCNAME is already running for $USER"
        echo "will sleep $EXTRA_DELAY seconds and then launch"
        sleep $EXTRA_DELAY
        echo "launching..."
        $BINNAME
    else
        echo "will wait $DELAY seconds for $PROCNAME"
    fi
    sleep $DELAY
done
```
Comment 24 homem.gustavo 2024-09-17 12:25:32 UTC
Some additional info:

* initially this problem was not happening to me
* but I fine-tuned the environment according to my preferences with the (nothing strange: favourites, background, widgets, etc)
* at some point this problem started to happen - I don't know at which point because I noticed it after rebooting the system upon tweaking
* the logs complained about kactivitymanagerd not being up so I scripted a loop that waist for kactivitymanagerd to be up
* but this is not enough because the process being up does not guarantee that plasmashell will startup correctly (the same problem was happening even after waiting for kactivitymanagerd to be up with the initial message about kactivitymanagerd not being up not being shown any more but still the desktop failing to load)
* I inserted an additional wait of 5s once kactivitymanagerd is detected as being up
* result: it seems to work (preliminary conclusion after a couple of reboots)

To sum up the most probable situation:

1. plasmashell only works after kactivitymanagerd is in a certain sane state
2. but plasmashell is launched in parallel without waiting for kactivitymanagerd to be in such state
3. this is a classic race condition: whether it happens or not depends on how many configuration files have been changed from the default, how many cores the system has, how fast each core is, the type of hdd, etc, etc...
4. ... which leads to "works on my computer" / "fails on my computer" type of situation

I think that the dependency between this components needs to be explicitly checked during the startup of the Plasma environment.

Environment: Dell XPS Developer Edition Core i7 1.8GHZ (4C/8T) with 16G RAM and SSD.
Comment 25 David Edmundson 2024-09-19 11:24:51 UTC
I did a dive, the root problem is plasma-activities library. 

The service status is tri-state on a consumer level: not running, started, unknown (booting)
Plasma handles that correctly.

The library code is completely broken. We're not correctly in the "unknown" state whilst launching kamd. We're in "not running". 
It only goes to unknown between the service being up and us having fetched the information.

We need to shift this tri-state enum lower down through the stack into manager_p.cpp
Comment 26 Bug Janitor Service 2024-09-19 12:36:44 UTC
A possibly relevant merge request was started @ https://invent.kde.org/plasma/plasma-activities/-/merge_requests/52
Comment 27 Nate Graham 2024-09-19 13:14:50 UTC
*** Bug 493303 has been marked as a duplicate of this bug. ***
Comment 28 Nate Graham 2024-09-20 16:57:58 UTC
*** Bug 492786 has been marked as a duplicate of this bug. ***
Comment 29 David Edmundson 2024-09-28 07:56:47 UTC
Git commit 9ac4e1db21f8ef1647023c24d91ac334d19b9b17 by David Edmundson.
Committed on 20/09/2024 at 13:06.
Pushed by davidedmundson into branch 'master'.

Avoid reporting serviceStatus of NotRunning whilst kamd is loading

Consumer::ServiceStatus is tri-state.
NotRunning, Unknown (loading), Running.

The backend was a simple boolean whether the service was up or not.
The library had code to try and start kactivitymanagerd on boot, or wait
until it is booted. However, this was not reflected in the service
status.

This leads to a race on plasma boot where the service status is reported
as "NotRunning" during initial startup.

A new enum is used as it's not a 1:1 match with Consumer::ServiceStatus,
when the backend is up, an async request of the activities is performed
and then the consumer is declared ready.

M  +18   -13   src/lib/activitiescache_p.cpp
M  +2    -1    src/lib/activitiescache_p.h
M  +27   -14   src/lib/manager_p.cpp
M  +9    -2    src/lib/manager_p.h

https://invent.kde.org/plasma/plasma-activities/-/commit/9ac4e1db21f8ef1647023c24d91ac334d19b9b17
Comment 30 David Edmundson 2024-09-28 08:04:43 UTC
Git commit a92e3199ac201fdb16ced9ce384e6960b555e379 by David Edmundson, on behalf of David Edmundson.
Committed on 28/09/2024 at 08:03.
Pushed by davidedmundson into branch 'Plasma/6.2'.

Avoid reporting serviceStatus of NotRunning whilst kamd is loading

Consumer::ServiceStatus is tri-state.
NotRunning, Unknown (loading), Running.

The backend was a simple boolean whether the service was up or not.
The library had code to try and start kactivitymanagerd on boot, or wait
until it is booted. However, this was not reflected in the service
status.

This leads to a race on plasma boot where the service status is reported
as "NotRunning" during initial startup.

A new enum is used as it's not a 1:1 match with Consumer::ServiceStatus,
when the backend is up, an async request of the activities is performed
and then the consumer is declared ready.


(cherry picked from commit 9ac4e1db21f8ef1647023c24d91ac334d19b9b17)

Co-authored-by: David Edmundson <kde@davidedmundson.co.uk>

M  +18   -13   src/lib/activitiescache_p.cpp
M  +2    -1    src/lib/activitiescache_p.h
M  +27   -14   src/lib/manager_p.cpp
M  +9    -2    src/lib/manager_p.h

https://invent.kde.org/plasma/plasma-activities/-/commit/a92e3199ac201fdb16ced9ce384e6960b555e379