GNOME Bugzilla – Bug 647778
applications loading isn't fast enough
Last modified: 2021-07-05 14:09:11 UTC
When you first click on the applications tab you can sit for a good 5 seconds with a blank screen. I'm assuming this is search the HD for .desktop files. Since the default is the "All" category I imaging this will get worse with slower hard drives and more applications. As a suggestion, could you show a waiting icon or load the icons as they are found. I've seen a few users think the gnome-shell is broken at that point.
*** Bug 647825 has been marked as a duplicate of this bug. ***
Okay, so I have this bug on my netbook for sure (Fedora 15 with partial jhbuild). Admittedly I didn't do any profiling at first and just guessed it was I/O, and ended up massively cleaning up the application code in bug 648149. Didn't help a bit. So I sat down to actually profile and debug this. Now, one thing I observed is that if I did Alt-F2 r, each time it would be very slow, but I didn't really observe the hard disk light much at all. So it isn't I/O. Not disk? Okay, must be CPU then. Fire up perf. Nothing stands out - the biggest CPU usage is 4% in librsvg, and the rest is a large scattering of 1-2% and less. Not disk, not CPU bound? Hmm...we must be blocking on some system call then. Owen hypothesized that we were spending a lot of time uploading textures - sounds very plausible. I haven't yet looked for tools to debug DRM specifically, but I thought I'd try strace. Here's what I used: mkdir /tmp/gs-apps; rm -f /tmp/gs-apps/*; strace -ttt -o /tmp/gs-apps/trace -ff -T -p $(pidof gnome-shell) So the results are very interesting and surprising - we're not blocking on DRM ioctls. The pixbuf loading threads are blocking for on the order of *seconds* on a mutex. In other words, the problem is thread contention. So I wrote a quick script to parse these strace results and sort the system calls by latency. Here's the result on one of the StTextureCache worker threads: syscall: 'futex' args: '0x940ce4c, FUTEX_WAIT_PRIVATE, 7, {14, 999511941}' result: '0' latency: 1.068685 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 260, {0, 499746524}' result: '-1 ETIMEDOUT (Connection timed out)' latency: 0.499973 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 47, {0, 488190520}' result: '-1 ETIMEDOUT (Connection timed out)' latency: 0.488351 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 192, {0, 499720505}' result: '0' latency: 0.265901 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 251, {0, 499665123}' result: '0' latency: 0.149814 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 33, {0, 499751269}' result: '0' latency: 0.143782 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 233, {0, 499725599}' result: '0' latency: 0.116903 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 217, {0, 499642591}' result: '0' latency: 0.107817 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 239, {0, 494809806}' result: '0' latency: 0.102327 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 70, {0, 499673843}' result: '0' latency: 0.101916 Note that it blocked for a full *second* on a mutex we'll call "mutex A", and repeatedly blocked on "mutex B" for a full tenth of a second. Here are the results from a second pixbuf worker thread: syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 263, {0, 499750266}' result: '-1 ETIMEDOUT (Connection timed out)' latency: 0.499968 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 194, {0, 499776663}' result: '0' latency: 0.280369 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 106, {0, 499652374}' result: '0' latency: 0.102555 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 236, {0, 499638466}' result: '0' latency: 0.100484 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 221, {0, 499721528}' result: '0' latency: 0.096608 syscall: 'futex' args: '0x9336094, FUTEX_WAIT_PRIVATE, 186, {0, 499662017}' result: '0' latency: 0.092422 Note the two worker threads are heavily contending for mutex B! The second thread appears not to block on mutex A though. So what we really need now are stack traces.
Without stack traces yet, one thing that does occur to me as a possibility is pango; see for example pango/pango/pangocairo-render.c:_pango_cairo_do_glyph_string. It grabs a lock for the full duration of drawing. We know this happens both in the main thread as well as the worker threads when they're loading an SVG.
So, I changed StTextureCache to not create new threads, and we spend the same total amount of time (about 5 seconds here). So bad mutex locking isn't the issue. If I rerun strace again, I see basically only the main thread active, and we spend *long* amounts of time blocked in poll(): '_llseek' total time: 0.04905699999999935 'read' total time: 0.058808999999999834 'gettimeofday' total time: 0.20409699999998782 'ioctl' total time: 0.26747200000000637 'poll' total time: 5.0851340000000045 The active fd returned each time is 7, which I'm pretty sure is the X server. As far as CPU now, sysprof shows ~15% of our time doing CSS style matching, 5% scaling pixbufs, and a lot of 1-2% scattered around. It could be that we're just doing too much work in one go.
Created attachment 186522 [details] [review] appDisplay: Create application actors incrementally This is a hack to work around how slow we are at processing apps right now. We process 5 applications at a time with a 150ms delay, which makes the system feel *much* more interactive.
The above is sort of a hack; creating even 100 application actors shouldn't be slow. But still, it's low risk, high gain for now - 3.0.1 material I think.
Strangely, though this was definitely happening for me earlier, now, even if I 'echo 3 > /proc/sys/vm/drop_caches' and restart the shell, switch to applications is more or less instant (certainly less than 0.25 seconds... obviously my laptop is much faster than your netbook, but that wouldn't explain the differences between what I was seeing earler, and this) That makes me wonder if the cause for the problems isn't some particular bad icon that is in SVG format or something. Certainly if you have a reproducible long hang, it should be tracked down while you are reproducing it. - Can you make it hang every time you switch to the overview by dumping the StIconCache, destroying the application tab, or dropping other cached information we have around? - If you can make it hang every time, can you write JS code to make the shell go into an infinite loop of switching tabs (maybe using the perf code, you can see examples of switching tabs already there), then get backtraces of where it's spending it's time by ssh'ing and gdb'ing?
Review of attachment 186522 [details] [review]: So, on my system, this takes the display that comes up instantly (small fraction of the second) and instead makes the apps pop in in 5 app chunks over ~2 seconds (66 apps / 5 apps per chunk * 0.150 seconds per chunk) ... this looks way worse. If anything, something like: this._pendingAppIdleId = Meta.later_add(Meta.LaterType.BEFORE_REDRAW, Lang.bind(this,this._addPendingApps)); add 5 apps per *frame* makes a lot more sense to me than adding 5 apps, pausing for an arbitrary 150ms, then adding 5 more apps, and so forth. But it's still pretty visible that the apps fill in incrementally. If the above doesn't work for you, then that's interesting in itself, because it might mean whatever is causing the blocking: - Isn't the creation of the actor (which is happening in a limited fashion per frame) - Isn't loading the icon (which shouldn't block anything, even if it's slow) - But is the work that is being done at completion of the load thread (which could all collapse together from multiple frames if the loads finished at the same time) Perhaps clutter st-texture-cache.c:pixbuf_to_cogl_handle()
(In reply to comment #7) > Strangely, though this was definitely happening for me earlier, now, even if I > 'echo 3 > /proc/sys/vm/drop_caches' and restart the shell, switch to > applications is more or less instant (certainly less than 0.25 seconds... > obviously my laptop is much faster than your netbook, but that wouldn't explain > the differences between what I was seeing earler, and this) That makes me > wonder if the cause for the problems isn't some particular bad icon that is in > SVG format or something. How many apps do you have installed? Shell.AppSystem.get_default().get_flattened_apps().length > Certainly if you have a reproducible long hang, it should be tracked down while > you are reproducing it. That's what I was trying to do with the above. > - Can you make it hang every time you switch to the overview by dumping the > StIconCache, destroying the application tab, or dropping other cached > information we have around? I'll work on this.
When I hit the Applications tab the first time it takes about 1.5 seconds until it is shown (though it feels longer). I have 135 apps shown there and my system specs are: Intel Core2 Duo CPU E8400 3.00GHz Nvidia GeForce 9600 GT with 512mb memory
I get the "hang" too. Not 5 seconds, but 2-3. Intel video, 107 apps. It doesn't appear to be related to filesystem caching at all; if I go to the apps view, then immediately restart gnome-shell and go the apps view again, it's slow the second time too.
The question now is: does this scale roughly linearly with number of apps, or are particular types of apps (e.g. SVG icons?) more likely to slow things down?
I added the seconds to my clock and in the apps view I noticed the clock stops for the 5 or so seconds. Don't know if that's any help tracking down the issue.
(In reply to comment #9) > (In reply to comment #7) > > Strangely, though this was definitely happening for me earlier, now, even if I > > 'echo 3 > /proc/sys/vm/drop_caches' and restart the shell, switch to > > applications is more or less instant (certainly less than 0.25 seconds... > > obviously my laptop is much faster than your netbook, but that wouldn't explain > > the differences between what I was seeing earler, and this) That makes me > > wonder if the cause for the problems isn't some particular bad icon that is in > > SVG format or something. > > How many apps do you have installed? > > Shell.AppSystem.get_default().get_flattened_apps().length 98 So, not way less than what other people are reporting. For a demo, I made some attempt to remove apps with bad/ugly icons, so it's possible that if it is a problem with particular a particular icon or icons, I might have removed them.
Created attachment 186613 [details] [review] appDisplay: Process application display in chunks instead of all at once Layout here can be slow for multiple reasons; better to avoid blocking the whole UI until we're done with layout.
So after debugging this more, we don't think there is a smoking gun. Some individual issues: https://bugzilla.gnome.org/show_bug.cgi?id=627083 https://bugzilla.gnome.org/show_bug.cgi?id=648638
Created attachment 186614 [details] collection of stack traces For reference, a collection of stack traces.
Review of attachment 186613 [details] [review]: This seems to work OK for me - there are definitely some visual artifacts as the apps load - for me I get labels appearing first, then icons then the scrollbar resizes, but it's likely better than a hang. ::: js/ui/appDisplay.js @@ +115,3 @@ + _addPendingApps: function() { + var i; + var startTimeMillis = new Date().getTime(); Our coding standard is to use 'let' .. with 2000+ uses of let in our code, it doesn't make sense to use var in one place even if you are the opinion that we should be using var and avoiding non-standardize extensions. @@ +118,3 @@ + for (i = 0; i < this._pendingAppIds.length; i++) { + var currentTimeMillis = new Date().getTime(); + if (currentTimeMillis - startTimeMillis > 75) { this should really be a constant broken out rather than a random number embedded into the code. @@ +127,3 @@ + if (this._pendingAppIds.length > 0) { + this._pendingAppIdleId = Meta.later_add(Meta.LaterType.BEFORE_REDRAW, + Lang.bind(this, this._addPendingApps)); shouldn't you just return true here, rather than adding a new id, then implicitly removing the later by return None which is boolean false? @@ +148,3 @@ + this._pendingApps = apps; + if (this._pendingAppIdleId) + Mainloop.source_remove(this._pendingAppIdleId); Not a mainloop source @@ +149,3 @@ + if (this._pendingAppIdleId) + Mainloop.source_remove(this._pendingAppIdleId); + this._pendingAppIdleId = Meta.later_add(Meta.LaterType.BEFORE_REDRAW, pendingAppLaterId or addPendingAppsId or something, it's not an idle.
Created attachment 186618 [details] [review] appDisplay: Process application display in chunks instead of all at once Updated for comments
Review of attachment 186618 [details] [review]: Just two minor stylish things. Good to commit with these fixed. ::: js/ui/appDisplay.js @@ +120,3 @@ + let currentTimeMillis = new Date().getTime(); + if (currentTimeMillis - startTimeMillis > MAX_APPLICATION_WORK_MILLIS) { + break; Very minor points, but excess brackets and this really should be at the end of the block not the beginning to save an extra syscall ... we always want to do at least one app.
Comment on attachment 186618 [details] [review] appDisplay: Process application display in chunks instead of all at once Attachment 186618 [details] pushed as 7813c5b - appDisplay: Process application display in chunks instead of all at once
Keeping this bug open, since I'm not really happy with the speed as is now.
*** Bug 649102 has been marked as a duplicate of this bug. ***
Created attachment 187112 [details] duplicated items I found some items in Applications are duplicated after I updated gnome-shell to 3.0.1 (see the attachment). After reverting the commit, the menu was normal again.
(In reply to comment #24) > Created an attachment (id=187112) [details] > duplicated items > > I found some items in Applications are duplicated after I updated gnome-shell > to 3.0.1 (see the attachment). After reverting the commit, the menu was normal > again. Hi Gary, This is fixed by: http://git.gnome.org/browse/gnome-shell/commit/?h=gnome-3-0&id=569008b08417d50b899266ba7c3eba4aee77c032
Oh! Thanks! It works for me :)
*** Bug 651879 has been marked as a duplicate of this bug. ***
*** Bug 663754 has been marked as a duplicate of this bug. ***
My request (663754) has been marked as duplicated of this. I don't think is quite the same. I asked the application search to be asyncronous, so typing don't halt while searching for the first one or two letters. Maybe only looking half a second after your last typed char. I think that would better the user experience.
(In reply to comment #29) > My request (663754) has been marked as duplicated of this. I don't think is > quite the same. I asked the application search to be asyncronous, so typing > don't halt while searching for the first one or two letters. Maybe only looking > half a second after your last typed char. I think that would better the user > experience. Colin said above he wanted to keep this bug open to deal with issues related to performance. No need to have several bugs open about that: you share the same goal of making the search responsive, and developers will choose the best solution to do that.
*** Bug 663841 has been marked as a duplicate of this bug. ***
I think this can be a solution: 1) At first time Gnome is opened, a file in a tree format is writen with the application load. If the file ("cache") content store a fast data structure, like a B-Tree, for example, will be fast to be loaded and updated. 2) A background proccess running to check the .desktop files change and update the cache file. I think it's an easy way, and the slow it's only at first time Gnome is used (KDE does something like this too). After this, the load and the update will be better than read the files one by one.
I believe gmenu already keeps its own cache around. The slow thing is loading the pixbufs and actors.
*** Bug 664359 has been marked as a duplicate of this bug. ***
*** Bug 669992 has been marked as a duplicate of this bug. ***
I can confirm that the delay is definitely not caused by I/O waiting. Restarting the gnome shell and then opening the applications tab exhibits the noticeable delay again, but only for the first time opening.
*** Bug 675073 has been marked as a duplicate of this bug. ***
In my opinion, this problem is annoying. The response time of the applications lists exceed any accepted limit for software developments. Programmers don't worry about this questions, but users, even if they do not know, reject Gnome each time they open the application list. Isn't me who affirm this, any software usability text talk something about the accepted response time. I'm posting this because I don't see importance to this problem since 2011-11-11. This problem come with Gnome since the first release! New users form their opinions at first time they use. How many potential users we possible have lost? How many time Gnome 3 is out? My suggestion: if we can't solve the load problem, put a load there! The load will give users the imediate response, and this will be better than click and don't know if is working or not. The effect of this load at users will be significant. I have no experience for now to submit a patch to Gnome, then, unfortunately, my contribution end here, where starts, but I will be here until see this problem fixed.
I don't think waiting for 10 or 11 seconds is annoying, however, there should be a label and a spinning wheel showing 'loading...' to tell the user to be patient. From the comments above, I found that drawing the icon costs the most time. Why not load the app screen with a 'loading' icon instead and draw the real icon in background a few seconds later? The most import thing is to be user-friendly, I think.
*** Bug 613814 has been marked as a duplicate of this bug. ***
*** Bug 684113 has been marked as a duplicate of this bug. ***
I think that wait 10 or 11 seconds is annoying, no other system takes that long, the user will complain about that.
Right now I believe this is caused by SVG, which should be fixed when we get librsvg off the main thread, which will be fixed when pango is thread-safe.
*** Bug 684112 has been marked as a duplicate of this bug. ***
Jasper, this would fix it even for slow cpus? Like netbooks or older hardware?
As far as I'm aware SVG is the major bottleneck of the overview.
Created attachment 225866 [details] [review] Force loading high-res bitmaps for non-recolored icons A PoC hack to show that we could load high-res bitmaps concurrently instead of blocking on loading SVGs consecutively. A final version of the patch would pass down the fact that we're loading menu icons and we'd force using bitmaps there.
Review of attachment 225866 [details] [review]: ::: src/st/st-texture-cache.c @@ +943,3 @@ + flags = GTK_ICON_LOOKUP_USE_BUILTIN; + if (colors) I think this is supposed to be !colors?
(In reply to comment #48) > I think this is supposed to be !colors? Yes. Can you tell it's completely untested? :)
Created attachment 226243 [details] [review] Force loading high-res bitmaps for non-recolored icons A PoC hack to show that we could load high-res bitmaps concurrently instead of blocking on loading SVGs consecutively. A final version of the patch would pass down the fact that we're loading menu icons and we'd force using bitmaps there.
Did you test this to ensure it improved performance?
(In reply to comment #51) > Did you test this to ensure it improved performance? Still not.
*** Bug 690298 has been marked as a duplicate of this bug. ***
*** Bug 690894 has been marked as a duplicate of this bug. ***
I have an Intel 1,66MHz CPU. It can't be a CPU issue. Previous GNOME 3 versions allowed me to search for apps with easiness. Now when I look for an app I have to wait for a while...and sometimes the display freezes and I can't do anything but button-shutdown it. It's surely a gnome-shell bug :)
entropy, your issue is not what this problem report is all about. Testing (Ubuntu) GNOME 3.6 on my old 1.6ghz single-core laptop, I can say the user experience has improved overall when compared to GNOME 3.0 / 3.2. The bottleneck now is opening the activities overview for the first time when there is still some delay you can notice on old hardware. However the delay used to be at least twice of what it is today (judging without a stopwatch).
Christian, Someone marked my bug as a duplicate of this bug.
testing on GNOME 3.6 on fedora 18 I can see a improvement, but for a such basic feature it could be faster. Considering the hardware Im running GNOME. Intel Core i5 2.4~3.0Ghz, 4gb DDR3, dedicated nvidia GPU.
GNOME is going to shut down bugzilla.gnome.org in favor of gitlab.gnome.org. As part of that, we are mass-closing older open tickets in bugzilla.gnome.org which have not seen updates for a longer time (resources are unfortunately quite limited so not every ticket can get handled). If you can still reproduce the situation described in this ticket in a recent and supported software version, then please follow https://wiki.gnome.org/GettingInTouch/BugReportingGuidelines and create a new ticket at https://gitlab.gnome.org/GNOME/gnome-shell/-/issues/ Thank you for your understanding and your help.