STR: 1. restart a firefox with a lot of open tabs => it takes a few seconds -- if not minutes, depending on the number of tabs -- to actually react to user input. It looks like it's somewhat exponential, as after a number of tabs, any new tab has an out-of-proportion impact. This happens for quite a long time but I never took the time to build a profile out of this. So here it is with latest nightly: https://cleopatra.io/#report=42d3ef91c66c10650b5bb2688ce40f8fe6e85a22&selection=0,1,2,2886,2,2887,2,4,2888,2,2351 It seems session restore eats up a lot of time.

I've been out of the loop for a while, but when I left, Allasso was working on something that might help a lot with the session restore startup. Allasso, I see that bug 1243707 has landed, did this complete your work or were there missing pieces?

David, bug 906076 to which you refer is dependent on bug 1287330, the actual structure of the lazy-browser tab which has gone through a bit of metamorphosis. That bug is currently held up on an intermittent and obscure test failure. Please see my last comments: https://bugzilla.mozilla.org/show_bug.cgi?id=1287330#c146

In case this is useful, here is another profile without any addons: https://cleopatra.io/#report=06062a9318b49dd5794e20d6254aea4d90c4b4bf

Julein, any chance you could please retry profiling this on Nightly with the new profiler add-on you can download from https://perf-html.io/? The new profiler makes it a lot easier to read the profiles. Will is going to be looking at sessionrestore performance issues so having an up to date profile should be very helpful. BTW, I would try increasing the default profiler buffer size so that you can capture a longer period of time during the initial restart, depending on how slow the restart is for you. The more of it you can capture in the profile, the better. I typically use between 90-180MB buffer sizes for use cases like this.

Sure, I'll do that when I'm back from PTO. FWIW I did a profile with the newer profiler for bug 1260036 and I left some conclusions in bug 1260036 comment 2. This may or may not be related. (I don't know why I haven't shared the profile itself, I'll do it again there too)

Ehsan, I can't seem to be able to capture the full restart with the new add-on. It looks like it doesn't start soon enough. Even increasing the buffer size doesn't change. So I get 6sec worth of data while my startup lasts 50 sec. Here it is in case you want it, but I doubt it's useful: https://perfht.ml/2mpEyn9 Any trick to capture the full startup ?

TIL: we can load old cleopatra profiles in the new perf tool. Here is the link: https://perf-html.io/public/42d3ef91c66c10650b5bb2688ce40f8fe6e85a22/calltree/?thread=0

(In reply to Julien Wajsberg [:julienw] from comment #6) > Ehsan, I can't seem to be able to capture the full restart with the new > add-on. It looks like it doesn't start soon enough. > > Even increasing the buffer size doesn't change. > So I get 6sec worth of data while my startup lasts 50 sec. Here it is in > case you want it, but I doubt it's useful: https://perfht.ml/2mpEyn9 > > Any trick to capture the full startup ? The best way that I know of is to increase the profiler buffer size to something really large (like 180MB and restart, wait for things to cool down and capture a profile. You can do that by clicking on the toolbar button, expand settings, move the buffer size slider and restart the profiler. Markus, is there a batter way?

The new add-on currently doesn't have any UI to allow capturing startup profiles. You'll have to resort to setting the environment variable MOZ_PROFILER_STARTUP=1 yourself. This env vars will make the profiler start as early as possible, long before add-ons like the Gecko Profiler add-on are loaded. See http://searchfox.org/mozilla-central/rev/571c1fd0ba0617f83175ccc06ed6f3eb0a1a8b92/tools/profiler/core/platform.cpp#1884 However, when the add-on is initialized, it calls StartProfiler again, and since the profiler will already be running, doing so will stop the profiler first, which will discard the data that was gathered during startup. This is not good. I'm going to update the add-on to avoid starting the profiler on initialization if it's already running.

I've updated the add-on. https://github.com/devtools-html/Gecko-Profiler-Addon/pull/32 Try starting your Firefox with MOZ_PROFILER_STARTUP=1 set. If it looks like the buffer is not large enough, or if you'd like a higher resolution, you can tweak the buffer size with the env var MOZ_PROFILER_ENTRIES (defaults to 1000000, which is 9MB). You can also choose a different interval using MOZ_PROFILER_INTERVAL, but it defaults to 1 and doesn't let you go below 1ms

Thanks! I managed to capture a profile! Here is the profile with latest nightly then: https://perfht.ml/2nsR4r5 There is a lot of data so it's quite slow ;)

As a comparison, here is a profile on the same computer, with the same nightly, with only one tab: https://perfht.ml/2mxGeva

The most striking aspect of that profile to me is the fact that we spend 20 seconds nuking cross-compartment wrappers, on the parent process. Ehsan, who do you think could debug this? I thought this had gotten better recently with mystor's work to create fewer DOMWindows in the parent process, but it looks like it hasn't helped much for this case.

What I don't understand is why we're already nuking things at startup ?

(In reply to Markus Stange [:mstange] from comment #13) > The most striking aspect of that profile to me is the fact that we spend 20 > seconds nuking cross-compartment wrappers, on the parent process. Ehsan, who > do you think could debug this? I thought this had gotten better recently > with mystor's work to create fewer DOMWindows in the parent process, but it > looks like it hasn't helped much for this case. Is this something that would only be happening when in multi-process mode? I have been noticing lately that startup times are significantly greater when in multi-process than when in single process, given the same profile. This, of course is just opposite of the behavior we hoped to achieve with multi-process.

(In reply to Markus Stange [:mstange] from comment #13) > I thought this had gotten better recently > with mystor's work to create fewer DOMWindows in the parent process I was confused here. What I was referring to was bug 1287330, which mystor had told me about, but he wasn't the one who worked on it. (In reply to Kevin Jones from comment #15) > Is this something that would only be happening when in multi-process mode? > I have been noticing lately that startup times are significantly greater > when in multi-process than when in single process, given the same profile. > This, of course is just opposite of the behavior we hoped to achieve with > multi-process. I don't know. And since you're the person who worked on lazy-browser tabs, you're probably the person I should have asked about this bug :) What's the status of the lazy browser tab work? Do you have any work in progress patches that you can run with the profiler and see whether they reduce the time spent in WindowDestroyedEvent::Run?

(In reply to Markus Stange [:mstange] from comment #16) > I don't know. And since you're the person who worked on lazy-browser tabs, > you're probably the person I should have asked about this bug :) > What's the status of the lazy browser tab work? Do you have any work in > progress patches that you can run with the profiler and see whether they > reduce the time spent in WindowDestroyedEvent::Run? bug 1345090 is the next step for tabs being able to restore lazily. I don't have any patches written for that yet. Nevertheless, if there is needless activity happening at startup, I think that should be addressed. If restoring to lazy-browser tabs somehow actually eliminates the needless activity, then very well.

Has bug 1256472 improved this?

The behavior is indeed different. What I see now: * it's a lot faster to get a responsive Firefox (a few seconds) * yet the tabs are not loaded until a lot of time (~30 sec with this computer), not even the one selected. So the behavior is arguably better but still not enough in my opinion. Here is a new profile with latest nightly: https://perfht.ml/2n0zHtQ It's not the same computer and not the same profile as before, so we can't directly compare the timings in this profile with the previous ones. I could do one later today on the other computer.

Bug 1348613 is the biggest source of suck in your profile, I think.

1.6 second of your time is wasted due to bug 1350781. This is particularly bad because at this time your content processes are doing work and in the mean time sync IPCing into the parent process and getting blocked on it, and making things much worse!

I suggest others also dig into the profile, especially other developers on their real profiles if they use a lot of tabs! I was quite happy with the number of low hanging fruit that I found so far.

This bug seems to me like a duplicate of bug 1025924. Shouldn't it be marked as a duplicate ?

Too late for firefox 52, mass-wontfix.

This is so much better now, thanks Ehsan! Here is a new profile from latest nightly: https://perfht.ml/2pXdZMt But from my point of view I consider this bug is now fixed. This is now 5sec instead of previously 50sec on the same computer.

Is "PollWrapper(_GPollFD*, unsigned int, int)" > "__poll" supposed to just end/die there with no further profiling?

"PollWrapper(_GPollFD*, unsigned int, int)" > "__poll" is what's on the callstack on Linux if the thread is idle. It indicates happiness.

(In reply to Julien Wajsberg [:julienw] from comment #25) > This is so much better now, thanks Ehsan! > > Here is a new profile from latest nightly: https://perfht.ml/2pXdZMt > But from my point of view I consider this bug is now fixed. This is now 5sec > instead of previously 50sec on the same computer. Okay, resolving.