Bug #1300722 “hud-service is eating up 100% of one of my CPUs in...” : Bugs : hud package : Ubuntu

Revision history for this message

Colin Ian King (colin-king) wrote on 2014-04-01:

#1

Dependencies.txt Edit (6.5 KiB, text/plain; charset="utf-8")
ProcEnviron.txt Edit (106 bytes, text/plain; charset="utf-8")
upstart.hud.log.txt Edit (190.0 KiB, text/plain; charset="utf-8")
upstart.window-stack-bridge.log.txt Edit (2.6 KiB, text/plain; charset="utf-8")

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-04-01:

#2

Hi Colin,

You see in the hud log there's a DBus address listed ":1.92". Can you see which application this is?

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-04-01:

#3

Indeed, there's a number of these instances. If I could find out which application it is that causes this, it'd help a lot with debugging.

Revision history for this message

Colin Ian King (colin-king) wrote on 2014-04-01:

#4

Hi Pete, how do I look that up?

Revision history for this message

Colin Ian King (colin-king) wrote on 2014-04-01:

#5

What I am seeing is the following poll:

poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
write(3, "\1\0\0\0\0\0\0\0", 8) = 8
write(3, "\1\0\0\0\0\0\0\0", 8) = 8
write(2, "\33[31mvoid DBusMenuImporter::slot"..., 335) = 335
write(2, "\33[31mbool DBusMenuImporterPrivat"..., 300) = 300
write(2, "\33[31mvoid DBusMenuImporter::slot"..., 115) = 115
sendmsg(13, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1 \0\0\0\354\243\2\0r\0\0\0\1\1o\0\33\0\0\0/com/can"..., 136}, {"n\3\0\0\6\0\0\0opened\0\1s\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 168
sendmsg(13, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1\4\0\0\0\355\243\2\0w\0\0\0\1\1o\0\33\0\0\0/com/can"..., 136}, {"\f\2\0\0", 4}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 140
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])

.. and this repeats and the timeout drops from 25000 milliseconds down to 1, which is a tad excessive. Polling a gazillion times with sub millisecond timeout is a little bit antisocial ;-)

What I am seeing is the following poll:

poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
	poll([{fd=13, events=POLLIN}], 1, 18813) = 1 ([{fd=13, revents=POLLIN}])
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
write(3, "\1\0\0\0\0\0\0\0", 8)         = 8
write(2, "\33[31mvoid DBusMenuImporter::slot"..., 335) = 335
write(2, "\33[31mbool DBusMenuImporterPrivat"..., 300) = 300
write(2, "\33[31mvoid DBusMenuImporter::slot"..., 115) = 115
sendmsg(13, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1 \0\0\0\354\243\2\0r\0\0\0\1\1o\0\33\0\0\0/com/can"..., 136}, {"n\3\0\0\6\0\0\0opened\0\1s\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 168
sendmsg(13, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1\4\0\0\0\355\243\2\0w\0\0\0\1\1o\0\33\0\0\0/com/can"..., 136}, {"\f\2\0\0", 4}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 140
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 25000) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])
poll([{fd=13, events=POLLIN}], 1, 24999) = 1 ([{fd=13, revents=POLLIN}])

.. and this repeats and the timeout drops from 25000 milliseconds down to 1, which is a tad excessive.  Polling a gazillion times with sub millisecond timeout is a little bit antisocial ;-)

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-04-02:

#6

Yes, this is definitely a bug, I'm not claiming otherwise.

To look up the application I would just use d-feet. Under the session bus, you can look up the connection name, and it will show you the process name at the bottom of the view.

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-04-02:

#7

Screen Shot 2014-04-02 at 09.42.37.png Edit (74.1 KiB, image/png)

Changed in hud (Ubuntu):
assignee:	nobody → Pete Woods (pete-woods)
status:	New → In Progress

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-04-02:

#8

Obviously those names are temporary. So if you close the window / application they will no-longer exist. Hopefully you can catch one while its still open.

Pete Woods (pete-woods) on 2014-04-02

Changed in hud:
importance:	Undecided → Critical
assignee:	nobody → Pete Woods (pete-woods)
status:	New → In Progress

Pete Woods (pete-woods) on 2014-04-02

Changed in hud:
status:	In Progress → Fix Committed

Colin Ian King (colin-king) on 2014-04-04

summary:

- hud-service is eating up 100% of one of my CPUs in a pool loop
+ hud-service is eating up 100% of one of my CPUs in a poll loop

Revision history for this message

Alexey Borzenkov (snaury) wrote on 2014-05-04:

#9

I'm not sure this issue is fixed. I'm running hud_13.10.1+14.04.20140402-0ubuntu1 (based on file ctime being April 7 and me running a kernel built on April 10) and I just got poll loop consuming 100% cpu in hud-service. Unfortunately I didn't debug this very much (my laptop was getting way too hot), and simply restarted hud-service. Logs in hud.log show only ~50 messages like:

Hit DBusMenu safety valve for menu at :1.135 /MenuBar/1

I would expect there would be a flood of these if this code path was hitting in a loop?

Revision history for this message

Alexey Borzenkov (snaury) wrote on 2014-05-04:

#10

Installed d-feet and found that :1.135 was kate, if that's important. Given previous screenshot showing gnome-terminal I doubt this is application specific.

Revision history for this message

Marcia (radio-m) wrote on 2014-05-05:

#11

I've seen the bug just once, since upgrading to Ubuntu 14.04. I have a 4-core CPU and HUD was consuming 100% of one of the cores; after a while it switched to consuming 100% of a different core. I noticed it because the fan started running quite fast, intermittently. After restarting Ubuntu the issue has not recurred. However when/if it happens, I do consider it critical. A user on a single-core machine would have a tough time debugging the problem with the CPU at 100%. I'm not exactly a Ubuntu geek but if someone wants to instruct me how to capture useful debug info, I could print it out and leave it next to the computer in case it happens again.

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-05-12:

#12

This is only going to happen for Qt apps, as they are still using the old DBusMenu protocol to export their menus.

I've tried running Kate and Kontact, as these are the apps I'm hearing that trigger this problem. Opening and closing them, switching around, and generally trying to operate the program hasn't caused it to happen for me yet. :(

If I could only reproduce this somehow, I could fix it!

Pete Woods (pete-woods) on 2014-05-12

Changed in hud:
status:	Fix Committed → Confirmed

Revision history for this message

Marcia (radio-m) wrote on 2014-05-13:

#14

Download full text (16.7 KiB)

Here's my system log spanning the time when the bug occurred. The log starts around the time when I used System Updater while playing chess, and ends at the place where I rebooted. I don't understand why there were so many thread creations owned by 1000 ... is that the symptom of this bug?

May 13 08:11:25 arpeggio AptDaemon: INFO: CommitPackages() was called: dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('account-plugin-aim'), dbus.String('account-plugin-jabber'), dbus.String('account-plugin-salut'), dbus.String('account-plugin-yahoo'), dbus.String('empathy'), dbus.String('empathy-common'), dbus.String('libfreetype6'), dbus.String('libfreetype6:i386'), dbus.String('liblightdm-gobject-1-0'), dbus.String('libnautilus-extension1a'), dbus.String('lightdm'), dbus.String('linux-firmware'), dbus.String('mcp-account-manager-uoa'), dbus.String('nautilus-data'), dbus.String('nautilus-sendto-empathy'), dbus.String('patch')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s'))
May 13 08:11:25 arpeggio AptDaemon.Trans: INFO: Queuing transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Simulating trans: /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Committing packages: dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([dbus.String('account-plugin-aim'), dbus.String('account-plugin-jabber'), dbus.String('account-plugin-salut'), dbus.String('account-plugin-yahoo'), dbus.String('empathy'), dbus.String('empathy-common'), dbus.String('libfreetype6'), dbus.String('libfreetype6:i386'), dbus.String('liblightdm-gobject-1-0'), dbus.String('libnautilus-extension1a'), dbus.String('lightdm'), dbus.String('linux-firmware'), dbus.String('mcp-account-manager-uoa'), dbus.String('nautilus-data'), dbus.String('nautilus-sendto-empathy'), dbus.String('patch')], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s'))
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Processing transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:12:17 arpeggio rtkit-daemon[1493]: Successfully made thread 5343 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:12:17 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:12:52 arpeggio dbus[483]: [system] Reloaded configuration
May 13 08:12:54 arpeggio NetworkManager[992]: <info> kernel firmware directory '/lib/firmware' changed
May 13 08:12:58 arpeggio AptDaemon.Worker: INFO: Finished transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:14:15 arpeggio rtkit-daemon[1493]: Successfully made thread 6171 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:15 arpe...

Here's my system log spanning the time when the bug occurred.  The log starts around the time when I used System Updater while playing chess, and ends at the place where I rebooted.   I don't understand why there were so many thread creations owned by 1000 ... is that the symptom of this bug?

May 13 08:11:25 arpeggio AptDaemon: INFO: CommitPackages() was called: dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s')), dbus.Array([dbus.String('account-plugin-aim'), dbus.String('account-plugin-jabber'), dbus.String('account-plugin-salut'), dbus.String('account-plugin-yahoo'), dbus.String('empathy'), dbus.String('empathy-common'), dbus.String('libfreetype6'), dbus.String('libfreetype6:i386'), dbus.String('liblightdm-gobject-1-0'), dbus.String('libnautilus-extension1a'), dbus.String('lightdm'), dbus.String('linux-firmware'), dbus.String('mcp-account-manager-uoa'), dbus.String('nautilus-data'), dbus.String('nautilus-sendto-empathy'), dbus.String('patch')], signature=dbus.Signature('s')), dbus.Array([dbus.String('')], signature=dbus.Signature('s'))
May 13 08:11:25 arpeggio AptDaemon.Trans: INFO: Queuing transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Simulating trans: /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Committing packages: dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s')), dbus.Array([dbus.String('account-plugin-aim'), dbus.String('account-plugin-jabber'), dbus.String('account-plugin-salut'), dbus.String('account-plugin-yahoo'), dbus.String('empathy'), dbus.String('empathy-common'), dbus.String('libfreetype6'), dbus.String('libfreetype6:i386'), dbus.String('liblightdm-gobject-1-0'), dbus.String('libnautilus-extension1a'), dbus.String('lightdm'), dbus.String('linux-firmware'), dbus.String('mcp-account-manager-uoa'), dbus.String('nautilus-data'), dbus.String('nautilus-sendto-empathy'), dbus.String('patch')], signature=dbus.Signature('s')), dbus.Array([], signature=dbus.Signature('s'))
May 13 08:11:25 arpeggio AptDaemon.Worker: INFO: Processing transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:12:17 arpeggio rtkit-daemon[1493]: Successfully made thread 5343 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:12:17 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:12:52 arpeggio dbus[483]: [system] Reloaded configuration
May 13 08:12:54 arpeggio NetworkManager[992]: <info> kernel firmware directory '/lib/firmware' changed
May 13 08:12:58 arpeggio AptDaemon.Worker: INFO: Finished transaction /org/debian/apt/transaction/f2d1b68012b5467ca9225b3252b23996
May 13 08:14:15 arpeggio rtkit-daemon[1493]: Successfully made thread 6171 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:15 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:22 arpeggio rtkit-daemon[1493]: Successfully made thread 6186 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:22 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:27 arpeggio rtkit-daemon[1493]: Successfully made thread 6195 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:27 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:31 arpeggio rtkit-daemon[1493]: Successfully made thread 6197 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:31 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:35 arpeggio rtkit-daemon[1493]: Successfully made thread 6199 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:35 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:41 arpeggio rtkit-daemon[1493]: Successfully made thread 6201 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:41 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:14:47 arpeggio rtkit-daemon[1493]: Successfully made thread 6203 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:14:47 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:15:18 arpeggio rtkit-daemon[1493]: Successfully made thread 6205 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:15:18 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:15:24 arpeggio rtkit-daemon[1493]: Successfully made thread 6208 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:15:24 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:15:39 arpeggio rtkit-daemon[1493]: Successfully made thread 6216 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:15:39 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:15:44 arpeggio rtkit-daemon[1493]: Successfully made thread 6220 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:15:44 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:16:09 arpeggio rtkit-daemon[1493]: Successfully made thread 6222 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:16:09 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:16:18 arpeggio rtkit-daemon[1493]: Successfully made thread 6226 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:16:18 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:16:29 arpeggio rtkit-daemon[1493]: Successfully made thread 6229 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:16:29 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:16:48 arpeggio rtkit-daemon[1493]: Successfully made thread 6237 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:16:48 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:16:56 arpeggio rtkit-daemon[1493]: Successfully made thread 6239 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:16:56 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:17:01 arpeggio CRON[6242]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
May 13 08:17:04 arpeggio rtkit-daemon[1493]: Successfully made thread 6244 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:17:04 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:17:25 arpeggio rtkit-daemon[1493]: Successfully made thread 6254 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:17:25 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:17:37 arpeggio rtkit-daemon[1493]: Successfully made thread 6264 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:17:37 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:17:50 arpeggio rtkit-daemon[1493]: Successfully made thread 6266 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:17:50 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:06 arpeggio rtkit-daemon[1493]: Successfully made thread 6269 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:06 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:15 arpeggio rtkit-daemon[1493]: Successfully made thread 6271 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:15 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:27 arpeggio rtkit-daemon[1493]: Successfully made thread 6275 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:27 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:31 arpeggio rtkit-daemon[1493]: Successfully made thread 6277 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:31 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:43 arpeggio rtkit-daemon[1493]: Successfully made thread 6279 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:43 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6290 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6292 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6294 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6296 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6298 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6300 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6302 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6304 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6306 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6308 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6310 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6312 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6314 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Successfully made thread 6316 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:53 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6318 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6320 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6322 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6324 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6326 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6328 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6330 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6332 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6334 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6336 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Successfully made thread 6338 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:18:55 arpeggio rtkit-daemon[1493]: Warning: Reached burst limit for user '1000', denying request.
May 13 08:18:57 arpeggio rtkit-daemon[1493]: message repeated 2 times: [ Warning: Reached burst limit for user '1000', denying request.]
May 13 08:19:20 arpeggio rtkit-daemon[1493]: Successfully made thread 6346 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:19:20 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:19:26 arpeggio rtkit-daemon[1493]: Successfully made thread 6349 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:19:26 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:19:39 arpeggio rtkit-daemon[1493]: Successfully made thread 6404 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:19:39 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:19:52 arpeggio rtkit-daemon[1493]: Successfully made thread 6439 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:19:52 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:20:17 arpeggio rtkit-daemon[1493]: Successfully made thread 6449 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:20:17 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:20:29 arpeggio rtkit-daemon[1493]: Successfully made thread 6452 of process 4838 (n/a) owned by '1000' RT at priority 2.
May 13 08:20:29 arpeggio rtkit-daemon[1493]: Supervising 7 threads of 3 processes of 1 users.
May 13 08:12:58 arpeggio dbus[483]: message repeated 2 times: [ [system] Reloaded configuration]
May 13 08:21:09 arpeggio dbus[483]: [system] Activating service name='org.freedesktop.hostname1' (using servicehelper)
May 13 08:21:09 arpeggio dbus[483]: [system] Successfully activated service 'org.freedesktop.hostname1'
May 13 08:23:25 arpeggio AptDaemon: INFO: Quitting due to inactivity
May 13 08:23:25 arpeggio AptDaemon: INFO: Quitting was requested
May 13 08:23:37 arpeggio dbus[483]: [system] Activating service name='org.freedesktop.systemd1' (using servicehelper)
May 13 08:23:37 arpeggio dbus[483]: [system] Successfully activated service 'org.freedesktop.systemd1'
May 13 08:05:03 arpeggio rsyslogd: message repeated 7 times: [ [origin software="rsyslogd" swVersion="7.4.4" x-pid="478" x-info="http://www.rsyslog.com"] rsyslogd was HUPed]
May 13 08:23:37 arpeggio rsyslogd: [origin software="rsyslogd" swVersion="7.4.4" x-pid="478" x-info="http://www.rsyslog.com"] exiting on signal 15.
May 13 08:24:05 arpeggio rsyslogd: [origin software="rsyslogd" swVersion="7.4.4" x-pid="479" x-info="http://www.rsyslog.com"] start

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-05-13:

#15

What I'm looking for is a way to cause this to happen by running a single application and performing a particular action in it. Even if it takes a number of tries that's fine. I just need to be able to trigger somewhat reliably within a few minutes.

I know exactly the part of the codebase that is getting sent into this loop, but I simply don't understand how it's getting there.

You can determine which application is the culprit by looking in "~/.cache/upstart/hud.log". In there you'll probably see it mentioning an application hitting a "safety value". The app will have an ID like ":1.22". If you use the application d-feet (see screenshot above) you will be able to figure out which application it is. The IDs are temporary, so if the window has closed, you won't be able to find out what application it was.

Revision history for this message

Marcia (radio-m) wrote on 2014-05-13:

#16

Thank you Pete. I will make a note of your instructions and try to get the identity of the application responsible to triggering the loop next time it happens.

At the present time the ~/.cache/upstart/hud.log does not contain the string "safety" ... but you did not expect it would after a reboot.

I will install d-feet. Can I invoke d-feet __after__ the onset of the 100% CPU problem? or does it have to be running all the time to be ready to trap the problem?

Let me just repeat back the instructions as I understand them, to make sure I have it right. When this problem happens again, first search the ~/.cache/upstart/hud.log for the string "safety-valve" and look for an app ID in the form similar to ":1.22". Then invoke d-feet and scan for the matching app ID. When I cursor over the matching app ID, the bottom left corner of the d-feet window should identify the app that triggered the polling loop. Then I will notify you by posting the info here and at that point it is OK to reboot the 100%-CPU system.

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-05-13:

#17

Just hit this again whilst browsing in firefox. The only Qt app I have running (I think) is spotify.

~/.cache/upstart/hud.log shows the offending entry as:

(hud-service:7316): GLib-GObject-CRITICAL **: g_object_unref: assertion 'G_IS_OBJECT (object)' failed
Hit DBusMenu safety valve for menu at :1.19 /com/canonical/menu/1600078
Hit DBusMenu safety valve for menu at :1.19 /com/canonical/menu/1600078
(ad infinitum)

d-feet shows 1:19 to be upowerd which appears to be doing squat:

$ sudo cat /proc/$(pidof upowerd)/stack
[<ffffffff811cd199>] poll_schedule_timeout+0x49/0x70
[<ffffffff811ce788>] do_sys_poll+0x428/0x540
[<ffffffff811ce975>] SyS_poll+0x65/0x100
[<ffffffff817266bf>] tracesys+0xe1/0xe6
[<ffffffffffffffff>] 0xffffffffffffffff

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-05-13:

#18

Unfortunately that's probably the system bus, rather than the session bus you looked at. Sorry for not being clearer.

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-05-13:

#19

Doh! Thankfully, I still have d-feet running and all the apps that were running before I had to kill hud-service. On the session bus, 1:19 is /usr/lib/firefox/firefox - the first object path I see for firefox is: /com/canonical/menu/1600078.

Presumably, we could add some extra details (atleast the pid) to DBusMenuCollector::openMenu() make tracking this issue down easier?

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-05-14:

#20

Hit it again, and again it is triggered by firefox.

Revision history for this message

Pete Woods (pete-woods) wrote on 2014-05-14:

#21

Just to check, you guys aren't even invoking HUD, right?

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-05-14:

#22

Correct.

Revision history for this message

Marcia (radio-m) wrote on 2014-05-14:

#23

Correct here too. I don't even know what HUD is :-)

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-05-15:

#24

hud.log Edit (13.2 KiB, text/plain)

Had 2 further cases of this in the last couple of days. What's interesting though is that I now have a script that monitors for CPU hogs. The script correctly detected hud-service spinning... *but* after a period of time (<1m), it stopped spinning. Attached is the log fwiw.

Revision history for this message

Greg A (etulfetulf) wrote on 2014-05-18:

#25

Screenshot from 2014-05-18 11:07:11.png Edit (323.9 KiB, image/png)

Firefox here too.

Revision history for this message

Marcia (radio-m) wrote on 2014-06-04:

#26

Screenshot from 2014-06-04 10:28:45.png Edit (422.7 KiB, image/png)

Just experienced this bug again. Hadn't seen it since my last report on May 13, 2014. This time I was ready with d-feet. Attached screen capture shows:

(1) CPU number 4 running at 100%

(2) Multiple instances of the string "safety value" in log ~/.cache/upstart/hud.log . The last one is DBus menu item :1.706 and it was hit several times. Also saw it one additional time a bit later in the log, also :1.706. (not shown in screen capture).

(3) d-feet, session bus tab, showing bus name :1.706 = process ID 31925 was started by command line
/usr/lib/firefox/firefox

Incidentally in the System Monitor, Processes tab, process ID 31925 is indeed Firefox. I had one instance of Firefox running in the background and it was on a web page that I visit frequently without problems (my.yahoo.com). I use the AdBlocker Plus plugin with Firefox. Also saw HUD service in Processes list.

Revision history for this message

Benjamin Brummernhenrich (spookyfm) wrote on 2014-06-29:

#27

This is my first time using Launchpad so please tell me if I'm doing anything wrong, leaving something out or shouldn't have posted:

The culprit is Firefox in my case too. If I close it, everything returns to normal. HOWEVER, on my machine, this only affects my wife's user account , not my own. If it helps I will provide logs for each of the two users the next time it occurs.

Revision history for this message

Benjamin Brummernhenrich (spookyfm) wrote on 2014-07-14:

#28

The problem is gone... I haven't changed anything (or been on this PC much since my original posting actually) and according to the changelogs there hasn't been an update in either Firefox or hud since then. No idea what caused this.

Revision history for this message

Marty Miller-Crispe (marty-millercrispe) wrote on 2014-07-15:

#29

Download full text (3.5 KiB)

I had this issue when I had qbittorent running for many days. top shows hud-service eating 99% cpu.
Closing qbittorrent fixed the issue.

The ~/.cache/upstart/hud.log

QDBusError("org.freedesktop.DBus.Error.InvalidArgs", "Unable to find windowId")
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "The name :1.289 was not provided by any .service files"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "The name :1.304 was not provided by any .service files"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'"
QCor...

I had this issue when I had qbittorent running for many days.  top shows hud-service eating 99% cpu.
Closing qbittorrent fixed the issue.

The ~/.cache/upstart/hud.log

QDBusError("org.freedesktop.DBus.Error.InvalidArgs", "Unable to find windowId") 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "The name :1.289 was not provided by any .service files" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "The name :1.304 was not provided by any .service files" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver
[31mvoid DBusMenuImporter::slotGetLayoutFinished(QDBusPendingCallWatcher*)[0m: "No such object path '/MenuBar/1'" 
QCoreApplication::postEvent: Unexpected null receiver

Revision history for this message

ABOUBAKR SEDDIK OUAHABI (ouahabix) wrote on 2014-07-27:

#30

It's been happening on my laptop since 13.04, and the reason was and still is (on 14.04) opening Nautilus on a Folder that contains either Photos and/or Videos, and once the Thumbnails are shown, then my i7 CPU feels like it's burning, really burning and the fan wants to fly, the hud-service goes crazy consuming both the CPU resources and the memory, which goes up to 1.7GB in no time. Surely it's a memory leak sort of thing.

Revision history for this message

jaime.undurraga (jaime-undurraga) wrote on 2014-07-30:

#31

it is sucking CPU and Memory. I have 32gb of RAM and hud-service was using 85% of it.

Revision history for this message

Christopher Serella (9e9o1ko8b2f5-chris-0zxvj9hhx1hz) wrote on 2014-08-03:

#32

I have been having an issue like this for a little over a week now. Oddly coinciding with when one of my ram sticks crapped out it could be that for whatever reason my previous ram total of 4gb was compensating and the problem could be older than i am aware of, in any case it seems the only time it happens for me is when i am running flash applications in chromium. Kill the hud and all comes back to normal.

If i don't catch it early enough then my system becomes virtually unusable so much so that i cant even get up the system monitor to kill the service.

As with others, it seems that as long as i dont have other applications running then i can scrape by with my browsing etc.

14.04LTS (daily updated)
x64
2GB ram

Revision history for this message

wilk (j-cubizolles) wrote on 2014-09-18:

#33

I've noticed it when running emacs-snapshot. emacs is very responsive at first but after a while (one hour more or less) it's unbearably slow. Moving the focus from one window to another takes a few seconds. When that happens, both emacs and hud-service cpu usage go up to 100% (I have a dual-core CPU).

Alberto Salvia Novella (es20490446e) on 2014-09-29

Changed in hud (Ubuntu):
importance:	Undecided → Critical

Revision history for this message

James Hunt (jamesodhunt) wrote on 2014-10-02:

#34

Just got this running hud 14.10+14.10.20140924-0ubuntu1. Just typing in a console and my CPU chewing script popped up a window to alert me to the fact.

Revision history for this message

muzzol (muzzol) wrote on 2015-01-15:

#35

I'm affected by this bug too.

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04.1 LTS
Release: 14.04
Codename: trusty

$ uname -a
Linux cprli0792 3.13.0-44-generic #73-Ubuntu SMP Tue Dec 16 00:22:43 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

$ dpkg -l | grep hud
ii hud 14.04+14.04.20140604-0ubuntu1 amd64 Backend for the Unity HUD
ii libhud2:amd64 14.04+14.04.20140604-0ubuntu1 amd64 library for exporting items to the Unity HUD

ask me for further info if you need it

Revision history for this message

Josh Steiner (josh-vitriolix) wrote on 2015-02-16:

#36

This just hit me this morning. I use a bluetooth keyboard and mouse on my sony vaios s15 laptop. turrning them off did nothing to stop the cpu pegging.

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04.1 LTS
Release: 14.04
Codename: trusty

$ uname -a
Linux stealth 3.13.0-45-generic #74-Ubuntu SMP Tue Jan 13 19:36:28 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

$ dpkg -l | grep hud
ii hud 14.04+14.04.20140604-0ubuntu1 amd64 Backend for the Unity HUD
ii libhud2:amd64 14.04+14.04.20140604-0ubuntu1 amd64 library for exporting items to the Unity HUD

Revision history for this message

Adrian (moshefeit) wrote on 2015-02-17:

#37

Wow you should "beautify" the log files, i got lost reading on it...

Revision history for this message

Joshua Holland (joshua-h) wrote on 2015-04-22:

#38

Just hit this whilst using Gimp (possibly due to a bug in Gimp). Editing an image, Gimp goes unresponsive (window fades), and CPU usage on *all four* cores goes up to 100%. Close Gimp, 3 cores settle down, but hud-service is still 100% on one core, using 1.3GB of RAM and rising. ~/.cache/upstart/hud.log doesn't actually seem to exist at the moment, although hud.log.1.gz etc. do. Therefore I can't do anything useful with d-feet, as I understand it.

Revision history for this message

aydin demircioglu (k-launchpad-cloned-de) wrote on 2015-05-04:

#39

here too on 15.04, and i do not know what triggered it.

Revision history for this message

Gabriel (gabriel-delepine) wrote on 2015-05-18:

#40

I'm also experiencing this bug. It started when I was using Chromium. Firefox and gimp was close. No torrent

Revision history for this message

Luís de Sousa (luis-de-sousa) wrote on 2015-05-27:

#41

I am experiencing this bug with Nemo on Ubuntu 15.04 64 bit. It does not start right away, it may take several hours working with Nemo before the HUD goes crazy.

Even with 4 CPUs and 8 Gb of RAM, the hud-service renders the system unusable once it forces the Swap to kick in.

Revision history for this message

Reuben Firmin (reubenf) wrote on 2015-05-31:

#42

Is this still being worked on? This happens to me at least weekly; on my computer, it happens overnight while the computer is idle, and I have to restart X to fix the situation.

Revision history for this message

ndstate (ndstate) wrote on 2015-06-19:

#43

This just started happening to me. ETA on a fix please...

Revision history for this message

muzzol (muzzol) wrote on 2015-08-25:

#44

several other machines are affected by this bug in our workplace.

not sure if it's worth to mention but one machine NOT displaying this behavior is a 32b system, while the rest are 64b.

adam thye (adam-adam-johannes) on 2015-09-07

affects:

hud → ufrs-apt

Revision history for this message

Robert (robertabcdefgwatson) wrote on 2015-10-15:

#45

Today I experienced this problem for the first time. The machine that had
the problem has been in operation for many years without this issue.

I want to draw attention to what ouahabix wrote in this thread back on 2014-07-27
as that would appear
to be the same as my experience. My machine is a MythTV recorder with a large
number of video recordings (1365 recordings across two directories). I do not
often use Nautilus on that machine, or use Nautilus in my video directory.

But in the last few days, I had been asked to copy one of the MythTV recordings
for someone and so I wanted to copy a recording to another machine and I
used Nautilus to do that. I did not close Nautilus. About 24 hours later I noticed the machine
was sluggish, and I notice hud-service was using a lot of CPU.

I am running 14.04 and keep the machine up to date with maintenance. I suspect
that ouahabix was on to something way back then. It may not the only cause, but
that observation and my experience are remarkably similar given that I haven't
experienced the problem until I did what ouahabix said would cause the problem.

Revision history for this message

muzzol (muzzol) wrote on 2016-05-31:

#46

I'm still hitting this bug in some machines.

Is there any known workaround?

Pete Woods (pete-woods) on 2017-04-10

Changed in ufrs-apt:
assignee:	Pete Woods (pete-woods) → nobody
Changed in hud (Ubuntu):
assignee:	Pete Woods (pete-woods) → nobody

Revision history for this message

Martin Bartlett (martin-j-bartlett) wrote on 2017-05-15:

#47

This is obviously long past the most recent thread activity, but just in case people fall on this page, I had this problem, as well as with evince-thumbnailer.

It turned out to be a permissions problem in my home folder tree. It probably came from some activity I had undertaken while sudoed - my bad, of course.

The solution was simply:

sudo chown -R <my_id>:<my_group_id> /home/<my_id>

Of course, that command may not be fully suitable if you have deliberate ownership differences within your home - adapt as necessary.

Võ Thành Luân (chaulenba686) on 2018-07-11

Changed in ufrs-apt:
status:	Confirmed → Fix Committed

Michael Troy (kwametsao) on 2019-01-13

Changed in hud (Ubuntu):
status:	In Progress → Fix Committed

tahasafari (tahasafari) on 2019-07-28

Changed in ufrs-apt:
status:	Fix Committed → Confirmed
Changed in hud (Ubuntu):
status:	Fix Committed → Incomplete
Changed in ufrs-apt:
status:	Confirmed → Fix Committed

amjith m (manu5458) on 2020-01-24

Changed in ufrs-apt:
status:	Fix Committed → Incomplete
status:	Incomplete → Fix Committed

	Status	Importance	Assigned to
Unity HUD	New	Undecided	Unassigned
unbuntu-fr Scripts - apt	Fix Committed	Critical	Unassigned
hud (Ubuntu)	Incomplete	Critical	Unassigned

Ubuntu
hud package

hud-service is eating up 100% of one of my CPUs in a poll loop

Bug Description

Related branches

Duplicates of this bug

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntuhud package

hud-service is eating up 100% of one of my CPUs in a poll loop

Bug Description

Related branches

Duplicates of this bug

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntu
hud package