GNOME Bugzilla – Bug 539313
big performance hit when starting playback immediately on startup
Last modified: 2010-02-26 17:15:11 UTC
I have done the following *warm start* startup performance "benchmarks". The numbers are 100% reproducible my end. Benchmark methodology: ====================== - warm start (rhythmbox has already been used recently in the session) - with a manual stopwatch, measure the time between the moment I click the RB launcher on my panel, and the moment where the "library loading" pulsating progress bar has gone away (and the hard drive has stopped thrashing) - this is with a 11200 songs collection on an ext3 partition, with a recent 7200 rpm hard drive, a Pentium 4 2.4 GHz CPU, and 1 Gio of RAM Test conditions and results: ============================ - if I let Rhythmbox start "undisturbed" (without forcing it to play music as soon as it can): startup time = 13 seconds - if asking to play a webradio ASAP: startup time = 20 seconds - if asking to play a local song file ASAP: startup time = 26 seconds Expectations (IRC discussion): ============================== <erwin> Well, reading two files stored contigouly on disk in sequence is faster than reading them in parallel. Seek times on disks are surprisingly high compared to the transfer rates improving.[...] <nekohayo> erwin: here is the very interesting catch; I did this test asking rhythmbox to play a *webradio*, not a local file. I would expect the startup time difference to be worse with local files. <erwin> My wild guess is that rhythmbox is going to read in and validate its library no matter what you ask it to play <nekohayo> I would expect at most 1-2 seconds of difference (CPU load perhaps?) when asking to play a web radio. 7-10 seconds seems a bit intriguing to me. <moch> what are you basing that expectation on? how are you arriving at 1-2 seconds? <nekohayo> well a webradio needs not to use the hard drive (I guess)? It should not impact much, since it's not supposed to eat the HDD, no? Besides, if I start RB, wait for it to fully load (13 seconds), and ask to play the webradio, the web radio starts playing between 1 and 2 seconds (and that includes stream buffering). So the total is still 14-15 secs instead of 20
forgot to mention: I have the "Watch for new files in the library" preference activated.
OK, now you get to learn about profiling tools. Here's a reasonable starting point: http://live.gnome.org/GnomePerformance Things you need to control for in any tests: Disk caches - either run it a few times before taking measurements to get warm caches, or 'echo 3 > proc/sys/vm/drop_caches' to get clear them first. Other system activity - make sure nothing else is using cpu or disk; maybe shut down cron to be safe. GStreamer registry - run gst-inspect immediately beforehand to ensure the gstreamer registry isn't being rebuilt No new files to import - if you have file monitoring enabled, it will scan for new files under your library directory and import any it finds. It would also be interesting to measure the impact of disabling file monitoring. Also, for this kind of work, you really need to be running an up to date build from svn trunk.
disk caches: as I was saying, this is 100% reproducible, I ran those tests more than 2-3 times each on my computer at least. No other task besides rhythmbox and IRC while doing the tests other system activity: well as I was not under any load and the "tests" provided me with consistent numbers, I am assuming that this was not the case gst registry: will have to try that I guess; I don't quite understand the concept of that registry thing, and why it would be rebuilt only when you start playback immediately no new files to import: check. I indeed have file monitoring enabled, but of course I did not have any file changes in the collection in the past few days. Besides, that should have affected the first try only, whereas the consistent startup times tell me that it's not the problem. disabling file monitoring: I'll have to test that too, though RB becomes nearly useless to me without it (I mean, might as well use xmms if you want a lightweight non-watching music player... ;) svn trunk: I doubt I could do that :| are you not able to reproduce my problem at all, by any chance? I'm assuming it must not be only my machine?
I have noticed something like this before on various machines. To make any improvement on this, someone needs to look into it in much more detail. I don't think there's a huge problem here (rb runs for hours or days, so <10s is neither here nor there), and I'd much rather spend my hacking time on something more interesting, so it's not likely to be me.
for the record, I just tried while disabling file monitoring: no difference at all.
This bug is set to NEEDINFO for quite some time now. I am reopening as I can't see any open question. Jonathan, feel free to close as WONTFIX if you don't think fixing this bug is reasonable. Or set to NEW if you think this bug is worth fixing. Jean, you might want to raise this issue on the mailing list get this issue resolved more quickly :)
I'm not going to close this as WONTFIX without knowing what the cause is, and as I said in an earlier comment, I'm not likely to do the work involved in determining the cause myself. So, NEEDINFO sounds like the right bug status.
Hm. Of course you are free to do whatever you want with your bugs. But it makes the work for the bugsquad harder if bugs are set to NEEDINFO without any question for the reporter. The "usual" state for bug is UNDECIDED, when it's not yet know whether it's an issue to fix or not a bug at all, i.e. because it depends on the machine used. So I recommend to not set this bug to NEEDINFO. Regarding this issue: Maybe a profiling tool such as callgrind or iogrind might help to determine the cause?
I thought it was pretty clear what information was required all along. At this stage, profiling data from any tool might help.
I changed computers since then, here are some new numbers. New warm startup times with a quadcore and new hard drive*: - warm start undisturbed: 6.5 seconds - warm start with radio playback: 5 seconds or less?! - warm start with library playback: 6 to 7 seconds New cold startup times (echo 3 > /proc/sys/vm/drop_caches): - cold start undisturbed: 15 seconds - cold start with radio playback: 16.5 seconds - cold start with library playback: 17 seconds It seems that the difference is not significant enough. Hmm. * Now here's some potential explanation. I believe that maybe the previous hard drive's file system, due to its extensive collection of files and music folders, may have become "folder fragmented": music files are not fragmented themselves, but they the files/folders are scattered on various parts of the disk, requiring excessive seeking, and moving all the music collection to a new drive "solves" the problem by making the 12000 files a "contiguous whole" again. The problem is that to confirm this hypothesis, I would need a "folder fragmentation" analyzer (but that kind of tool doesn't exist, as far as I know). Regarding profiling data: the profiling wiki page is unhelpful for mortals. I did try to use those various profiling tools and have failed for all but sysprof, but then sysprof doesn't work anymore in recent kernels (https://bugs.launchpad.net/ubuntu/intrepid/+source/sysprof/+bug/272204) so I'm unable to provide profiling data. I have to say that the fact that profiling in gnome still seems to be rocket science/black magic (ie., that it /seems/ that there isn't a special gnome project tailored for allowing the average user to provide profiling data easily) is both funny and sad :)
Hey Jean, (In reply to comment #10) > Regarding profiling data: the profiling wiki page is unhelpful for mortals. :( > I > did try to use those various profiling tools and have failed for all but Have you tried callgrind / KCachegrind? See http://valgrind.org/info/tools.html I assume they are actually usable, though I haven't tried them myself yet. > so I'm > unable to provide profiling data. I propose to close this bug report as INCOMPLETE if no further information in provided in reasonable time, then. > I have to say that the fact that profiling in > gnome still seems to be rocket science/black magic (ie., that it /seems/ that > there isn't a special gnome project tailored for allowing the average user to > provide profiling data easily) is both funny and sad :) > Indeed. I am sorry, that I can't help you with that. Maybe an experienced debugger/developer might help... However, if you gain any new knowledge or have ideas how to make that wiki page better, feel free to add that information to the wiki.