Bug 1177683

Summary: gnome-shell uses 50% CPU constantly when gnome-shell-extension-background-logo is enabled
Product: [Fedora] Fedora Reporter: Christopher Beland <beland>
Component: gnome-shell-extension-background-logoAssignee: Florian Müllner <fmuellner>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: high Docs Contact:
Priority: unspecified    
Version: 21CC: bruce, chkr, dmitry.ursegov, dtrudg, enaut.w, fmuellner, jone1941, kalevlember, lantw44, mailingdotlist, mspaulding06, otaylor
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: gnome-shell-extension-background-logo-3.14.0-2.fc21 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-04-29 13:08:34 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
journalctl | grep gnome (since last reboot)
none
Idle gnome profiling
none
Proposed patch to fix the high CPU usage none

Description Christopher Beland 2014-12-29 20:36:59 UTC
Created attachment 974206 [details]
journalctl | grep gnome (since last reboot)

gnome-shell uses about 50% of my CPU all the time.  This did not happen on Fedora 20, but it does happen on Fedora 21.  (I upgraded using FedUp.)

I see a lot of other bugs with high CPU usage, but they are all reported against Fedora 19 or 20.

The only programs that load on startup are Evolution and HipChat; I see high CPU usage by gnome-shell immediately after that.  The only Gnome Extension I have enabled is Background Logo, which I think is enabled by default.

There are lot of gnome-session errors in my system log, which I'll attach.

gnome-shell-3.14.2-1.fc21.x86_64

Comment 1 Christopher Beland 2014-12-29 20:43:20 UTC
I turned off Evolution and HipChat startup on login; that didn't make a difference.

With just gnome-terminal and top running on the desktop, I see low CPU usage from them, X, what look like kernel bits, and mousetweaks.

Comment 2 Dmitry Ursegov 2015-01-03 11:36:49 UTC
Can confirm this issue on MacBook Air 5.2.

strace shows a lot of EAGAIN from some unix sockets:

poll([{fd=35, events=POLLIN}, {fd=4, events=POLLIN}, {fd=10, events=POLLIN}, {fd=26, events=POLLIN}, {fd=13, events=POLLIN}, {fd=32, events=POLLIN}, {fd=30, events=POLLIN}, {fd=31, events=POLLIN}, {fd=11, events=POLLIN}, {fd=24, events=POLLIN}, {fd=21, events=POLLIN}, {fd=5, events=POLLIN}], 12, 16044) = 1 ([{fd=5, revents=POLLIN}])
recvmsg(5, {msg_name(0)=NULL, msg_iov(1)=[{"#\223:\231\0\0\0\0\2\0\0\0(\0\340\0\20\0\340\0Fg\27\0-\0\340\0.\0\340\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 104
recvmsg(5, 0x7fffafa87900, 0)           = -1 EAGAIN (Resource temporarily unavailable)
write(4, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(5, 0x7fffafa877c0, 0)           = -1 EAGAIN (Resource temporarily unavailable)
write(4, "\1\0\0\0\0\0\0\0", 8)         = 8
recvmsg(5, 0x7fffafa878e0, 0)           = -1 EAGAIN (Resource temporarily unavailable)
recvmsg(10, 0x7fffafa878c0, 0)          = -1 EAGAIN (Resource temporarily unavailable)

lsof:
gnome-she 1537 dmitry    5u     unix 0xffff88008a3bec80       0t0   24388 socket
...
gnome-she 1537 dmitry   10u     unix 0xffff880089a63480       0t0   25290 socket

Comment 3 Dmitry Ursegov 2015-01-11 09:55:45 UTC
Created attachment 978703 [details]
Idle gnome profiling

Comment 4 Dmitry Ursegov 2015-01-11 10:28:06 UTC
I noticed that if I switch to a virtual tty gnome stops hogging the cpu. So I attached by gdb to it and temporary switched back to the UI and forth. The breakopint on recvmsg shows the following stack trace, when the return value is -1:

Breakpoint 2, recvmsg () at ../sysdeps/unix/syscall-template.S:81                                                                                                                   81      T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)                                                                                                                      (gdb) fin                                                                                                                                                                           Run till exit from #0  recvmsg () at ../sysdeps/unix/syscall-template.S:81                                                                                                          0x00007f17991e30a7 in _xcb_in_read () from /lib64/libxcb.so.1                                                                                                                       (gdb) p $eax                                                                                                                                                                        $10 = -1                                                                                                                                                                            (gdb) bt                                                                                                                                                                            #0  0x00007f17991e30a7 in _xcb_in_read () from /lib64/libxcb.so.1                                                                                                                   #1  0x00007f17991e3928 in poll_for_next_event () from /lib64/libxcb.so.1                                                                                                            #2  0x00007f1799e90a28 in poll_for_event (dpy=dpy@entry=0x772560) at xcb_io.c:257                                                                                                   #3  0x00007f1799e91498 in _XReply (dpy=dpy@entry=0x772560, rep=rep@entry=0x7fffe8788ca0, extra=extra@entry=0, discard=discard@entry=0) at xcb_io.c:626                              #4  0x00007f179a195078 in XIGetClientPointer (dpy=0x772560, win=win@entry=0, deviceid=deviceid@entry=0x7fffe8788d04) at XGetCPtr.c:59                                               #5  0x00007f179e31385d in update_client_pointer (manager_xi2=manager_xi2@entry=0x1e00250) at x11/clutter-device-manager-xi2.c:234                                                   #6  0x00007f179e3146fe in clutter_device_manager_xi2_translate_event (translator=0x1e00250, native=<optimized out>, event=<optimized out>) at x11/clutter-device-manager-xi2.c:817  #7  0x00007f179e33b8ac in clutter_backend_real_translate_event (backend=<optimized out>, native=0x7fffe8788e40, event=0x505b250) at ./clutter-backend.c:629                         #8  0x00007f179e30efe2 in clutter_x11_handle_event (xevent=xevent@entry=0x7fffe8788e40) at x11/clutter-event-x11.c:200                                                              #9  0x00007f179ef36ff4 in handle_host_xevent (event=0x7fffe8788e40, backend=0x76f370) at backends/x11/meta-backend-x11.c:232                                                        #10 x_event_source_dispatch (source=<optimized out>, callback=<optimized out>, user_data=<optimized out>) at backends/x11/meta-backend-x11.c:285                                    #11 0x00007f179b470aeb in g_main_dispatch (context=0x768400) at gmain.c:3111                                                                                                        #12 g_main_context_dispatch (context=context@entry=0x768400) at gmain.c:3710                                                                                                        #13 0x00007f179b470e88 in g_main_context_iterate (context=0x768400, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3781                           #14 0x00007f179b4711b2 in g_main_loop_run (loop=0x22d72d0) at gmain.c:3975                                                                                                          #15 0x00007f179ef5d958 in meta_run () at core/main.c:473                                                                                                                            #16 0x00000000004023dd in main (argc=1, argv=0x7fffe87891c8) at main.c:463

I'm not sure this is very useful.

The more useful thing is a perf report in the idle state. I attached the call graph here.
The following functions are always on the top:
   4.34%  libc-2.20.so                     [.] __GI___strcmp_ssse3
   3.33%  ld-2.20.so                       [.] _dl_find_dso_for_object
   2.84%  libglib-2.0.so.0.4200.1          [.] g_hash_table_lookup
   1.41%  libc-2.20.so                     [.] _int_malloc
you can look at the call graph to figure out the callers.

Comment 5 Matt Jones 2015-02-04 18:28:06 UTC
Confirmed on a macbook air 6,2.  Approximately 200 EAGAIN errors per second on two different unix sockets immediately after login.

Comment 6 David Trudgian 2015-02-08 15:00:33 UTC
Also seeing this on a macbook air 6,2. Constant 30-50% cpu usage in an idle gnome session, with continuous EAGAIN in strace as above. Did not happen in Fedora20 on same machine. Fedora21 was a clean install.

Comment 7 Matt Jones 2015-02-09 21:32:52 UTC
Apparently Fedora 21 started installing a number of non-standard gnome-shell extensions:

gnome-shell-extension-window-list-3.14.3-1.fc21.noarch
gnome-shell-extension-common-3.14.3-1.fc21.noarch
gnome-shell-extension-launch-new-instance-3.14.3-1.fc21.noarch
gnome-shell-extension-user-theme-3.14.3-1.fc21.noarch
gnome-shell-extension-alternate-tab-3.14.3-1.fc21.noarch
gnome-shell-extension-background-logo-3.14.0-1.fc21.noarch
gnome-shell-extension-places-menu-3.14.3-1.fc21.noarch
gnome-shell-extension-apps-menu-3.14.3-1.fc21.noarch

Obviously YMMV but try disabling (or uninstalling) the following extension:

gnome-shell-extension-background-logo

When I disable this specific extension the CPU load drops to normal (comparable to Fedora 20). Enabling it causes CPU utilization to jump back up to consistently >30% utilization.  I toggled this extension on/off using the gnome-shell extension management page:

https://extensions.gnome.org/local/

Comment 8 David Trudgian 2015-02-10 02:40:26 UTC
Confirmed - if I disable the 'Background Logo' extension via https://extensions.gnome.org/local/ then the gnome-shell idle cpu usage drops to <1%.

I did some more digging, and noticed that I it seems to be an issue with certain logo files only, chosen from /usr/share/pixmaps via the extension's settings panel. E.g. the 'fedora-logo.svg' logos causes approx 50% CPU. The 'fedora-logo.png' PNG format logo has the same issue. However, if I choose 'fedora-logo-sprite.png' or 'fedora-logo-sprite.svg' I do not see the gnome-session idle CPU above 1%.

Anyway, turning it off means I don't need an alternative desktop to get good battery life. Thanks!

Comment 9 Christopher Beland 2015-02-11 16:12:43 UTC
For security reasons I don't have browser integration enabled for Gnome extensions.  However, extensions can be controlled by running gnome-shell-extension-prefs.  When I disable gnome-shell-extension-background-logo in that UI, CPU usage of gnome-shell settles to a much more tolerable baseline of around 1%.

I have my desktop set to a PNG of Mars, and even with the background-logo extension enabled, I don't actually see the logo on either of my monitors.  When I'm in the background-logo settings in gnome-shell-extension-prefs, I don't see my actual desktop background in the preview area; I see the default Fedora 21 background with the logo overlaid on it.

Given this plugin is not working reliably and is sucking up CPU cycles, and doesn't seem to have much point anyway, maybe it should just be dropped from the standard distribution?

Comment 10 Dietrich 2015-04-04 18:44:54 UTC
I have the same issue...

Also this Bug is a duplicate from: #1171480

I'd mark it as a duplicate but I think I do not have the rights necessary. Or I just can't find the right button.

Comment 11 Christian Krause 2015-04-05 14:27:10 UTC
*** Bug 1171480 has been marked as a duplicate of this bug. ***

Comment 12 Christian Krause 2015-04-05 16:57:23 UTC
Created attachment 1011192 [details]
Proposed patch to fix the high CPU usage

The reason of the problem seems to be some kind of "feedback loop":

At some point, the size of the overlay image is updated via _icon.set_size(). This triggers an "allocation-changed" event which calls _updateScale() and _icon.set_size() again. The problem seems to happen if the newly set size and the eventually allocated size differ slightly due to rounding issues (that's why the problem does not always happen).

@Florian: I have attached a patch against https://git.fedorahosted.org/cgit/background-logo-extension.git/ which applies also to the F21 version of the extension. Please have a look if my bug fix is correct and consider committing it upstream.

With respect to this fedora bug report: since this issue causes a bad first impression of Fedora (just a simple new Fedora installation will contain the package), it would be great if the Fedora package could be updated as well. 

Given the OK from the package owner, I'd volunteer to do it (via proven-packager privs).

Comment 13 Fedora Update System 2015-04-16 19:18:29 UTC
gnome-shell-extension-background-logo-3.14.0-2.fc21 has been submitted as an update for Fedora 21.
https://admin.fedoraproject.org/updates/gnome-shell-extension-background-logo-3.14.0-2.fc21

Comment 14 Florian Müllner 2015-04-16 19:20:11 UTC
(In reply to Christian Krause from comment #12)
> Please have a look if my bug fix is correct and consider committing it upstream.

Looks good to me, thanks! I did a 3.16.1 release including the patch for F22, and filed an update for F21.

Comment 15 Fedora Update System 2015-04-18 09:46:37 UTC
Package gnome-shell-extension-background-logo-3.14.0-2.fc21:
* should fix your issue,
* was pushed to the Fedora 21 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing gnome-shell-extension-background-logo-3.14.0-2.fc21'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2015-6345/gnome-shell-extension-background-logo-3.14.0-2.fc21
then log in and leave karma (feedback).

Comment 16 Matt Jones 2015-04-20 14:36:21 UTC
Confirmed. This updated version resolves the CPU issue for me.  However, I think it is worth noting that I don't actually see the fedora logo anywhere on my desktop when I enable this extension.  I have tried adjusting all of the settings within this extension and none of them make a logo appear anywhere on either of my monitors.

Comment 17 Dietrich 2015-04-20 14:51:54 UTC
I can confirm too! I can't see any performance issue anymore.

@ Matt Jones The Logo appears only on the default wallpaper which makes this extension more or less useless but that is another bug ;) try out with the default wallpaper and you should see the logo!

Comment 18 Matt Jones 2015-04-20 15:10:37 UTC
Wow, thanks @Dietrich I didn't realize just how pointless this extension was.  Confirmed CPU load also remains low when the logo appears on the default background.

Comment 19 Florian Müllner 2015-04-23 11:22:41 UTC
(In reply to Dietrich from comment #17)

> @ Matt Jones The Logo appears only on the default wallpaper which makes this
> extension more or less useless but that is another bug ;)

It is a workaround. With the launch of Fedora Workstation, there was a push to increase the Fedora branding, and adding the logo to the (default) wallpaper was the agreed solution (rather than patching up GNOME to display the logo in the top bar or elsewhere). However *actually* putting the (trademarked) logo in the wallpaper would conflict with Fedora's policy of having artwork freely redistributable, so this is what we ended up with instead ...

Comment 20 Fedora Update System 2015-04-29 13:08:34 UTC
gnome-shell-extension-background-logo-3.14.0-2.fc21 has been pushed to the Fedora 21 stable repository.  If problems still persist, please make note of it in this bug report.