GNOME Bugzilla – Bug 664891
Long Epiphany start up time
Last modified: 2014-10-03 14:08:46 UTC
Epiphany is taking between 5 and 8 seconds (!) to start up. This is consistent whether fired from command line or via a keyboard shortcut. It feels like something is making a call out and waiting to timeout, but of course it could be anything. Once Epiphany is running new windows start promptly, and web page loading is fine. It's something about application initialization. I assume it's something about my environment that is out of whack, but I could really use some help isolating the problem. Is there any tracing or debug output that can be activated? I have 3.2.1 installed. AfC
Launch ephy with -p, see if the same happens. If it doesn't it's likely that your history or bookmarks are b0rked somehow.
(In reply to comment #1) > Launch ephy with -p, see if the same happens. Unfortunately the same delay happens. Now that I'm timing it with a stop watch, it's averaging 9.5 s to start in both modes. DBus timeout? Startup notification borked? Hm. AfC
(In reply to comment #2) > Unfortunately the same delay happens. Now that I'm timing it with a stop watch, > it's averaging 9.5 s to start in both modes. > > DBus timeout? Startup notification borked? Hm. Hrm, yeah, not sure, could be a bunch of things. It would be useful if you could install the debug packages and launch ephy with gdb to see what's going on. Another wild guess: is NM installed and working? Xan
Ok, installed. Other than noting that it took a fairly long time for [Thread debugging using libthread_db enabled] to appear, (about 1/3 of load time) is there a set of functions you'd like to suggest that I break on to incrementally) see timings? Presumably if we can see the distribution of time between major entry points we might find the one that is being dilatory for me. AfC
(In reply to comment #4) > Ok, installed. > > Other than noting that it took a fairly long time for > > [Thread debugging using libthread_db enabled] That is, I think, libsoup resolving a hostname, so that means the time is being consumed before any URL is loaded. Makes sense. > > to appear, (about 1/3 of load time) is there a set of functions you'd like to > suggest that I break on to incrementally) see timings? Presumably if we can see > the distribution of time between major entry points we might find the one that > is being dilatory for me. I'd say break on main() and see if anything eats the time before the GApplication is run. That should be a good starting point. > > AfC
This is all a bit thin, but: (gdb) break main Gives 37 seconds consistently across several runs. Ok, so that's how long GDB takes to get started. Running without the break point took ~45 seconds for the epiphany main window to come up, which is interesting because 45 - 37 = 8 is of the same order as the startup time delay I am experiencing. At random in there I took several ^C as SIGINT, and quite a few times I saw: soup_cache_load ephy_embed_single_initialize ephy_window_constructor on the stack. One time I saw more than that, specifically,
+ Trace 229183
Does that mean that soup_cache_load() is my problem? [or rather, that something on my system is causing soup_cache_load() a problem?]
Hrm! I think -p should not use the user soup cache, but perhaps that's broken. Try to move away (do not delete it, we might need it for testing!) the directory ~/.cache/epiphany and see what happens.
sorry, a little bit more. After threads initialized and main() hit, I started interrupting roughly every 2 seconds, then taking a backtrace, then continuing: Program received signal SIGINT, Interrupt. g_list_length (list=<optimized out>) at /build/buildd/glib2.0-2.30.0/./glib/glist.c:906 906 in /build/buildd/glib2.0-2.30.0/./glib/glist.c (gdb) bt
+ Trace 229184
Definitely something weird about [whaver] soup_cache_load() [is causing to happen]. AfC
(In reply to comment #7) > Try to move away (do not delete it, we might need it for testing!) the > directory ~/.cache/epiphany and see what happens. Wow, that did it. Moving the ~/.cache/epiphany-browser/ directory (and it's 16000 files) out of the way has resulted in an ~/.cache/epiphany-browser/ of a few hundred files and subsecond Epiphany start times. Whoa. Um. Hm. What did Andrew do wrong, he wonders? Ooooh. Now that we're talking about cache I remember I upped the "temporary disk space" setting to 500 MB. Didn't think it'd be a problem. After all, I have lots of diskspace and was tired of sites I visit regularly being squeezed out by random day-to-day surfing. I'm guessing I shouldn't have done that. But given that one _can_ do that, and have this result would probably count as a bug. Still, 500 MB of cache and 16K files shouldn't bother much of anything. I will *not* reset it to normal in the interest of seeing if Epiphany's start time degrades over the next few days. If this is the culprit, then it will. AfC
Thank you! CCing sergio, who is the mastermind behind this ;)
So yeah, in order to sort this out we'll have to asynchronously load the contents of cache. Will try to get a patch ready during the hackfest.
Created attachment 202472 [details] [review] Patch So basically the actual load is moved to an idle callback. There are a couple of questions here: - do we prefer a thread for that? - should we add a callback to the soup_cache_load() call?
Taking 37 seconds to read the cache is awful regardless of whether you do it blocking, asynchronously, or in a thread. In particular, we really shouldn't be keeping the message headers of every response in the cache in memory...
oh, that was in gdb. still...
(In reply to comment #12) > So basically the actual load is moved to an idle callback. There are a couple > of questions here: > > - do we prefer a thread for that? Not up on the Epiphany internals, of course, but personally, I would recommend "yes"; if you do it in an idle callback it had better be something you can do in tinsy increments because the first thing after someone loads their browser they're either already going to be loading a page (if they have a home page set and/or launched with a URL) or typing an address into the Location GtkEntry ... so I'd assume you kinda want the main loop to be ready and able to be snappy responsive and not caught off in some idle callback. Anyway. (In reply to comment #13) > Taking (8-10 seconds, consistent both normally or after the ~35 second GDB startup time) > to read the cache is awful regardless of whether you do it > blocking, asynchronously, or in a thread. It is rather astonishing, yes. I would have thought an index + some mmap'ing would have been eaiser than rebuilding the structure in memory at runtime. {shrug} I'll report back if performance degrades again over the next few days, but in the mean time I'll get out of the Epiphany hackers' way and leave this bug for you guys to discuss patches on. AfC
Comment on attachment 202472 [details] [review] Patch We were changing libsoup so that this thing is not needed right?
(In reply to comment #16) > We were changing libsoup so that this thing is not needed right? yeah, bug 665884 changes the cache format to not store the response headers in the cache index file, making it much smaller and therefore faster to read in
Sergio, would it make sense to mark this a duplicate of bug #665884?
(In reply to comment #18) > Sergio, would it make sense to mark this a duplicate of bug #665884? Yep
*** This bug has been marked as a duplicate of bug 665884 ***