After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 687669 - opening the user menu blocks the compositor thread
opening the user menu blocks the compositor thread
Status: RESOLVED FIXED
Product: gnome-shell
Classification: Core
Component: general
3.6.x
Other Linux
: Normal normal
: ---
Assigned To: gnome-shell-maint
gnome-shell-maint
Depends on:
Blocks: 687362
 
 
Reported: 2012-11-05 16:57 UTC by Simon McVittie
Modified: 2014-01-13 00:06 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
strace log (420.83 KB, text/x-log)
2012-11-05 16:57 UTC, Simon McVittie
Details
strace log, repeating the test (252.67 KB, text/plain)
2012-11-05 17:02 UTC, Simon McVittie
Details
sysprof for first log (96.98 KB, application/octet-stream)
2012-11-05 17:04 UTC, Simon McVittie
Details
sysprof for repeat log (91.66 KB, application/octet-stream)
2012-11-05 17:05 UTC, Simon McVittie
Details

Description Simon McVittie 2012-11-05 16:57:26 UTC
Created attachment 228152 [details]
strace log

+++ This bug was initially created as a clone of Bug #687362 +++

Opening the user menu performs I/O in the main thread, blocking the compositor for a short time.

Some highlights of the attached log:

Lines 1884-2013 block for 47ms, including stat() on icon theme directories and some blocking RPC (X11?) calls.

Lines 2618-3042 are the main problem area, blocking for 172ms.

Line 2621 polls whether I have a ~/.face (I don't). After that, there are some X11(?) round trips, then a 27ms pause before starting to do DRI operations. For some reason these have access() on fonts interspersed into them (I still haven't found which library does that).

Near line 2837 there are some significant pauses between operations.

Near line 2844, the main thread wakes up the GDBus thread while apparently still holding locks that the GDBus thread wants, leading to some contention for ~1ms. When they've finished fighting over futexes, the main thread carries out a couple of X11(?) round trips, then pauses for 34ms without I/O, allocates some more memory, and starts doing DRI.

At line 2959 the main thread loads toggle-on-us.svg in a blocking way, then stat()s MIME-related files. This is relatively quick in my log, but could take time if the disk is busy.
Comment 1 Simon McVittie 2012-11-05 17:02:56 UTC
Created attachment 228154 [details]
strace log, repeating the test

There's less blocking the second time, but not necessarily a whole lot less: this log shows a 100ms block, much of which can be blamed on a series of mprotect() calls taking 30ms. The stat() and access() near the beginning are still there, and so is the pause after X11(?) round-trips.
Comment 2 Simon McVittie 2012-11-05 17:04:35 UTC
Created attachment 228155 [details]
sysprof for first log

Corresponding to Attachment #228152 [details].

9.25% is in arch_local_irq_restore(), presumably context-switch overhead?
3.58% is in additional_selector_matches_style().
3.28% is in string_in_list().
Comment 3 Simon McVittie 2012-11-05 17:05:16 UTC
Created attachment 228156 [details]
sysprof for repeat log

corresponding to Attachment #228154 [details]
Comment 4 Jasper St. Pierre (not reading bugmail) 2014-01-13 00:06:02 UTC
The user menu was revamped recently and I can't notice any slowdown. Closing.