Bug 93084 - High CPU usage of dbus-daemon on resume from suspend
Summary: High CPU usage of dbus-daemon on resume from suspend
Status: RESOLVED NOTOURBUG
Alias: None
Product: dbus
Classification: Unclassified
Component: core (show other bugs)
Version: 1.10
Hardware: x86-64 (AMD64) Linux (All)
: medium major
Assignee: D-Bus Maintainers
QA Contact: D-Bus Maintainers
URL:
Whiteboard:
Keywords: NEEDINFO, regression
Depends on:
Blocks:
 
Reported: 2015-11-23 21:26 UTC by SET
Modified: 2016-07-04 10:36 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments
Error from dbus-monitor (106.93 KB, text/plain)
2015-11-23 21:26 UTC, SET
Details

Description SET 2015-11-23 21:26:23 UTC
Created attachment 120070 [details]
Error from dbus-monitor

Using DBUS 1.10.2 on Arch Linux with KDE5

After resume from suspend, dbus-daemon goes in a loop and consumes one CPU core at 100%. No way to workaround that, apart from reverting to 1.8.20. 

dbus-monitor --profile --system gives the error in the attachement, that I don't know how to interprete.

That's a sort of BSOD ! Please consider a resolution.
Comment 1 Simon McVittie 2015-11-24 11:22:49 UTC
(In reply to SET from comment #0)
> After resume from suspend, dbus-daemon goes in a loop and consumes one CPU
> core at 100%. No way to workaround that, apart from reverting to 1.8.20. 

Something is repeatedly connecting to the bus, being told "no, you can't", and disconnecting.

Do you have some sort of ACPI hook script that runs "dbus-monitor --system" as an unprivileged user, in a loop?
Comment 2 Simon McVittie 2015-11-24 11:28:35 UTC
Looking at the systemd journal (assuming Arch Linux uses systemd) would probably also be informative.

(In reply to SET from comment #0)
> That's a sort of BSOD ! Please consider a resolution.

Please talk to Arch Linux's support channels. They can hopefully help you to find which component is doing this, and if it is in fact a D-Bus bug, provide enough information to locate and fix that bug.

Until that information can be provided, the upstream developers of D-Bus are not going to be able to help you.
Comment 3 SET 2015-11-24 14:31:31 UTC
> Do you have some sort of ACPI hook script that runs "dbus-monitor --system"
> as an unprivileged user, in a loop?

You hit the right point. I have 2 bash scripts with "dbus-monitor --system" running. They detect successful network connection from NetworkManager. If I deactivate these scripts, the problem gets resolved with 1.10.2. Something here has changed in DBus, with a regression on my setup.

Now I have to find a less smarter way to do this.

Sorry to have bothered you; and thank you for your input and prompt reply.
Comment 4 Simon McVittie 2015-11-24 17:46:09 UTC
(In reply to SET from comment #3)
> I have 2 bash scripts with "dbus-monitor --system"
> running.

Running as who? An unprivileged user, or root?

dbus-monitor --system never worked properly for what it was meant to do (monitor all bus traffic, including spying on other connections) - Bug #46787. Since 1.9.something, it has used a new Monitoring interface which does that correctly, but for security reasons, is restricted to be used by root.

The only thing that worked reliably with the old "eavesdropping" mechanism was watching for broadcast signals, which is presumably how you were using dbus-monitor in your scripts.

If you aren't root, newer dbus-monitor versions will fall back to the old "eavesdropping" mechanism after printing a warning similar to this:

archetype% dbus-monitor --system
dbus-monitor: unable to enable new-style monitoring: org.freedesktop.DBus.Error.AccessDenied: "Rejected send message, 1 matched rules; type="method_call", sender=":1.7047" (uid=1000 pid=15830 comm="dbus-monitor --system ") interface="org.freedesktop.DBus.Monitoring" member="BecomeMonitor" error name="(unset)" requested_reply="0" destination="org.freedesktop.DBus" (bus)". Falling back to eavesdropping.

They can still receive broadcast signals, though; I don't know why your local scripts are restarting dbus-monitor in a loop. Perhaps the warning message is being parsed?

To watch for broadcasts on D-Bus, I would recommend replacing Bash scripts using dbus-monitor with similar scripts in a scripting/programming language that can connect to D-Bus itself, such as Python (with python-gi, txdbus or dbus-python to provide access to D-Bus), Perl (Net::DBus), JavaScript (gjs or seed), or even PHP (DBus). Bash is not well-suited to this particular task.
Comment 5 SET 2015-11-24 19:53:36 UTC
> Running as who? An unprivileged user, or root?

As unprivileged user (my session).

The script fails on resume from suspend ONLY.


Here is the relevant usage :

dbus-monitor --system "type='signal',interface='org.freedesktop.NetworkManager',member='StateChanged'" |\

I'm trying to do something when "StateChanged" reports a successful network connection. This statement gives a stdout message similar to what you have posted when it is invoked while the PC is NOT resuming from suspend.

/*dbus-monitor: unable to enable new-style monitoring: org.freedesktop.DBus.Error.AccessDenied: "rejected attempt to call BecomeMonitor by connection :1.50 (uid=1001 pid=4085 comm="dbus-monitor --system type='signal',interface='org") with uid 1001". Falling back to eavesdropping.*/

The script is always loaded and naturally blocks on the above line. Network connection may or may not be configured to restart on resume. So "StateChanged" does not seem to be the issue. It seems that on resuming from suspend, the new monitoring interface does not fall back to eavesdropping. Could it be that this particular resuming instance needs to addressed by the new code ? 

Thx.
Comment 6 Simon McVittie 2016-07-01 16:33:52 UTC
(In reply to SET from comment #5)
> /*dbus-monitor: unable to enable new-style monitoring:
> org.freedesktop.DBus.Error.AccessDenied: "rejected attempt to call
> BecomeMonitor by connection :1.50 (uid=1001 pid=4085 comm="dbus-monitor
> --system type='signal',interface='org") with uid 1001". Falling back to
> eavesdropping.*/

Having dbus-monitor operate on the system bus, with feature parity with how it would work on the session bus, requires being root.

uid 1001 is not allowed to monitor the system bus, because that would be a security vulnerability (violating the confidentiality of unicast messages on the system bus).

It is possible to watch for broadcast signals (only) while using the old way (eavesdropping), and that *can* work while unprivileged. If that is enough for what you're doing, you could teach your script to understand and ignore that line.

This appears to be a bug in your script, not a bug in dbus-daemon.

If you want to watch for events on the system bus, I would strongly recommend using a real programming language - I'd use Python, with either python-gi + Gio.DBusConnection or dbus-python. Shell scripts are not a good solution for handling asynchronous events.

The high load from the dbus-daemon appears to be because your script is reconnecting in a loop. This is not a dbus-daemon bug; if you want to avoid your script consuming resources, stop reconnecting.
Comment 7 SET 2016-07-01 18:31:29 UTC
> This appears to be a bug in your script, not a bug in dbus-daemon.

I modified the script to get it working. In a few words, formerly, the script would raise another instance of itself before dying, after having detected the network status change. The new script never exits.

**************************OLD******************************
dbus-monitor --system "type='signal',interface='org.freedesktop.NetworkManager',member='StateChanged'" |\
while read line;do
    if [ "$(qdbus --system org.freedesktop.NetworkManager /org/freedesktop/NetworkManager org.freedesktop.NetworkManager.state)" = "70" ];then
        #Do something
    fi
    break
done

#Call ourself again. This is what triggerred high CPU usage.
$0 &

exit 0
***********************************************************

**************************NEW******************************
while true;do
dbus-monitor --system "type='signal',interface='org.freedesktop.NetworkManager',member='StateChanged'" |\
while read line;do
    if [ "$(qdbus --system org.freedesktop.NetworkManager /org/freedesktop/NetworkManager org.freedesktop.NetworkManager.state)" = "70" ];then
        #Do something
    fi
    break
done
done

exit 0
***********************************************************
Comment 8 Simon McVittie 2016-07-04 09:25:29 UTC
(In reply to SET from comment #7)
> formerly, the
> script would raise another instance of itself before dying
...
> #Call ourself again. This is what triggerred high CPU usage.
> $0 &

It turns out busy-looping leads to high CPU usage. Who knew? :-)
Comment 9 SET 2016-07-04 10:36:06 UTC
(In reply to Simon McVittie from comment #8)

> It turns out busy-looping leads to high CPU usage. Who knew? :-)

Everyone, except < 1.8.20, where the CPU was cold :-)


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.