Closed Bug 1135719 Opened 9 years ago Closed 1 year ago

[meta] [e10s] tracking bug for page render times when switching tabs

Categories

(Core :: Graphics, task, P3)

task

Tracking

()

RESOLVED FIXED
Tracking Status
e10s - ---

People

(Reporter: gw280, Unassigned)

References

(Depends on 1 open bug, Blocks 1 open bug)

Details

(Keywords: meta, Whiteboard: gfx-noted)

Attachments

(3 files)

spin-off from bug 1066531. this bug is specifically about the issue seen where we can spend a long time (>300ms) rendering a page and causing the spinner to be shown to the user for long periods of time.

Possibly related to bug 1129223.
Assignee: nobody → davidp99
Whiteboard: gfx-noted
Blocks: 1111396
I feel like we've put a lot of work into improving tab switch times. There's not a lot of low hanging fruit left. Maybe this should be m7 or m8.
Depends on: 1066531
waiting on bug 1132072 and bug 1066531 to land before we decide what to do with this.
To be clear, this bug is about profiling and improving paint times, rather than tab switching times. Bug 1132072 and bug 1066531 landing will give us a better indication of how often we hit degenerate painting cases that take longer than 300ms, so that we can make a better decision on how much we want to prioritise this work.

Another conversation that could be worth having is what timeout should we set for the spinner to appear? Is 300ms too long? Do we have statistical data on how long it takes for our users to get mozAfterRemotePaint after making a request?
(In reply to George Wright (:gw280) from comment #3)
> To be clear, this bug is about profiling and improving paint times, rather
> than tab switching times. Bug 1132072 and bug 1066531 landing will give us a
> better indication of how often we hit degenerate painting cases that take
> longer than 300ms, so that we can make a better decision on how much we want
> to prioritise this work.
> 
> Another conversation that could be worth having is what timeout should we
> set for the spinner to appear? Is 300ms too long? Do we have statistical
> data on how long it takes for our users to get mozAfterRemotePaint after
> making a request?

We don't, but it might be worth putting in a telemetry probe to try to measure this.

Cc'ing vladan.
Also, putting in profile markers for the pointer when we start requesting the new tab, and we actually render the new tab would probably be good.
Assignee: davidp99 → gwright
Blocks: e10s-perf
No longer blocks: 1111396
My profile. Saw a few times the throbber, once for a second or so:
https://www.dropbox.com/s/6ous1r1w5ejrcu7/CxwClFrC?dl=0
(In reply to Eugene Savitsky from comment #6)
> My profile. Saw a few times the throbber, once for a second or so:
> https://www.dropbox.com/s/6ous1r1w5ejrcu7/CxwClFrC?dl=0

Thanks Eugene. Is this a custom build of Firefox? I can't seem to find symbols for it.
Flags: needinfo?(ezh)
Nightly 40.0a1 (2015-05-05)

If you need more, than I can do more. I noticed that the throbber appears when loading some heavy page in other tab.
Flags: needinfo?(ezh)
Here are many throbbers for loong times.
https://www.dropbox.com/s/n0r904ska9p21hb/K3IKP4nc?dl=0
Bah - profiles from Windows (and probably Linux) are probably going to be useless until bug 1161720 gets fixed[1]. :(

Watch this space, folks. Until that gets fixed, profiles from those platforms are likely not going to be helpful. Hopefully it'll get fixed in the next few days.

[1]: Unless people are running their own build and are running their own symbol server, which I suspect is a small population.
(In reply to Marco Castelluccio [:marco] from comment #11)
> This is on Linux: https://dl.dropboxusercontent.com/u/34104919/oaHE6tG9.7z

Thank you Marco.

Looking at that profile, something is taking a humongous amount of time (about 600ms) computing whether or not ContentPolicy should load something, which is sending a bunch of sync messages to the parent and blocking the main process.

Can you list your enabled add-ons?
Flags: needinfo?(mar.castelluccio)
ADB Helper	0.7.4	true	adbhelper@mozilla.org
Adblock Plus	2.6.9	true	{d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d}
API Enabler	0.7.0	true	@tcpsocketpup
Better MXR	0.2.1	true	jid0-ePBKtqqSeez8ThB1NInNoY7B0xc@jetpack
Firefox OS 2.0 Simulator	2.0.20140918	true	fxos_2_0_simulator@mozilla.org
Gecko Profiler	1.15.7	true	jid0-edalmuivkozlouyij0lpdx548bc@jetpack
HTitle	3.4	true	{c6448328-31f7-4b12-a2e0-5c39d0290307}
HTML5 Video Everywhere!	0.2.35	true	html5-video-everywhere@lejenome.me
Valence	0.3.0	true	fxdevtools-adapters@mozilla.org

> Looking at that profile, something is taking a humongous amount of time (about 600ms) computing whether or not ContentPolicy should load something, which is sending a bunch of sync messages to the parent and blocking the main process.

This might be AdBlock Plus.

The "hideous spinner" is often displayed when I open pages of online newspapers.
Flags: needinfo?(mar.castelluccio)
(In reply to Marco Castelluccio [:marco] from comment #13)
> ADB Helper	0.7.4	true	adbhelper@mozilla.org
> Adblock Plus	2.6.9	true	{d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d}
> API Enabler	0.7.0	true	@tcpsocketpup
> Better MXR	0.2.1	true	jid0-ePBKtqqSeez8ThB1NInNoY7B0xc@jetpack
> Firefox OS 2.0 Simulator	2.0.20140918	true	fxos_2_0_simulator@mozilla.org
> Gecko Profiler	1.15.7	true	jid0-edalmuivkozlouyij0lpdx548bc@jetpack
> HTitle	3.4	true	{c6448328-31f7-4b12-a2e0-5c39d0290307}
> HTML5 Video Everywhere!	0.2.35	true	html5-video-everywhere@lejenome.me
> Valence	0.3.0	true	fxdevtools-adapters@mozilla.org
> 
> > Looking at that profile, something is taking a humongous amount of time (about 600ms) computing whether or not ContentPolicy should load something, which is sending a bunch of sync messages to the parent and blocking the main process.
> 
> This might be AdBlock Plus.
> 
> The "hideous spinner" is often displayed when I open pages of online
> newspapers.

Would you mind disabling Adblock Plus for a little while to see if that eases the issue? If so, we can file a new bug blocking 930787. If the spinner is still prevalent, we'll dig in deeper.
Flags: needinfo?(mar.castelluccio)
Disabling AdBlock definitely eases the issue (I can't seem to make the spinner show again, while with AdBlock enabled it's displayed whenever I load a page with many images).
Flags: needinfo?(mar.castelluccio)
Ok, filed bug 1161798 for the Adblock Plus issue.
I'm noticing the same issue as Eugene in comment#8 for a while now (running on Nightly Linux).

If I open a new tab, all tabs (even if they have been loaded) will, eventually, have the spinner until the new tab that is loading finishes loading. In other words, I see the throbber in *all* tabs not necessarily the one loading.
If it helps, while the tab is loading I can switch tabs for a few seconds without seeing the big throbber.
Soon after the big throbber appears, sometimes, the whole browser is blocked until that tab finishes loading. Not always.

Could this be caused by doing drawing on the top of the new tab that is being loaded?
When we open a new tab we have a small spinner on the tab itself.

NOTE: Disabling all add ons take this away.
Whitelisting mozilla.org on ABP and Ghostery was not good enough (even though it would improve a bit - I think).

Side note, I also think that my typing issues on GH are also gone (not sure yet).
I would sometimes see delays on my typing.
I've also noticed issues on Firefox Hello calls when I would load a new tab I would loose audio for a bit.
I narrowed it down to LastPass as the biggest offender.

ABP and Gohstery would add a bit of throbbing.
Depends on: 1176007
Depends on: 1176019
Depends on: 1180916
Milan, what do you think we should do about this class of bugs? They all seem to be related to painting performance.
Flags: needinfo?(milan)
We are looking at paint performance, so if there is a particular scenario product thinks is important, just send us the individual bug.  They'll go in a queue that we'll try to keep sorted by importance, and look at them.  And sometimes get stuck (e.g., bug 1180916), but in general deal with them.
Flags: needinfo?(milan)
Priority: -- → P2
Thanks to Mozilla engineers who try to deal with this bug, but should not it be elevated to higher priority with more software engineers assigned to fix it?

The issue is that I am seeing spinning wheels during tab switching even right after fresh start of a session. And the longer I use it, the longer I am looking at blank screen with spinning wheel on it instead of target tab.

This behaviour is basically invalidating whole Electrolysis project, making it fundamentally unusable.
Can you attach the text of your about:support page?
Flags: needinfo?(zxspectrum3579)
Weirdly enough, the report is totally empty. I see all sections, but the right column, where actual data for Name/Version/ID/User agent/etc should be, it blank. Copying either raw data or text to clipboard also copies just sections/parameter names without any information.
Flags: needinfo?(zxspectrum3579)
This spinning wheel is sometimes does not show up if tab is rendered quickly, or last for 0.5 seconds, or sometimes even about 1 seconds or for longer if it is, say, YouTube complex layout.
(In reply to User Dderss from comment #23)
> Thanks to Mozilla engineers who try to deal with this bug, but should not it
> be elevated to higher priority with more software engineers assigned to fix
> it?

The problem is that there are so many potential individual causes for this problem, where the problem is "the content process is busy".

I can see from the screenshot that you just posted that you have some add-ons installed. If you restart with add-ons disabled (from the Help menu), do you see the same behaviour with the spinner? If not, then we need to identify which add-on(s) are contributing.

And if so, then we need to figure out what your Firefox is doing during that span of time (perhaps by gathering a performance profile[1]).

[1]: https://www.youtube.com/watch?v=kGBs0BQsoQg
(In reply to Mike Conley (:mconley) - Needinfo me! from comment #27)

> The problem is that there are so many potential individual causes for this
> problem, where the problem is "the content process is busy".
> 
> I can see from the screenshot that you just posted that you have some
> add-ons installed. If you restart with add-ons disabled (from the Help
> menu), do you see the same behaviour with the spinner? If not, then we need
> to identify which add-on(s) are contributing.
> 
> And if so, then we need to figure out what your Firefox is doing during that
> span of time (perhaps by gathering a performance profile[1]).
> 
> [1]: https://www.youtube.com/watch?v=kGBs0BQsoQg

I thought that in safe mode e10s will get automatically turned off, no matter what "remote" preferences say? (There was bug for that with "resolved fixed" result and no recall on the feature.)

If so, could you please say how I can force e10s even Safe mode? I did not find information on that.
(In reply to User Dderss from comment #28)
> (In reply to Mike Conley (:mconley) - Needinfo me! from comment #27)
> 
> > The problem is that there are so many potential individual causes for this
> > problem, where the problem is "the content process is busy".
> > 
> > I can see from the screenshot that you just posted that you have some
> > add-ons installed. If you restart with add-ons disabled (from the Help
> > menu), do you see the same behaviour with the spinner? If not, then we need
> > to identify which add-on(s) are contributing.
> > 
> > And if so, then we need to figure out what your Firefox is doing during that
> > span of time (perhaps by gathering a performance profile[1]).
> > 
> > [1]: https://www.youtube.com/watch?v=kGBs0BQsoQg
> 
> I thought that in safe mode e10s will get automatically turned off, no
> matter what "remote" preferences say? (There was bug for that with "resolved
> fixed" result and no recall on the feature.)
> 
> If so, could you please say how I can force e10s even Safe mode? I did not
> find information on that.

Since bug 1172491, e10s remains active in safe mode.
I switched to Safe mode while e10s still on.

While there was no spinner when there was some moderate number of tabs activated, after certain number, in more advanced use FF 45b4 started to show spinner even when switching to tabs that were just rendered shortly before, and became very slow overall. 

For example, this very text I am typing is mostly not visible to me during the process since it appaears on the screen only after second or two seconds delay.

Memory foot print data currently:
1) FireFox 45b4 itself: 1 GB;
2) plugin-container 1:  3 GB, in few minutes grew to 4 GB (with no new tabs opened/activated);
3) plugin-container 2: 1.7 GB;
-- 5.5-6.5 GB total.

As also can be seen on the screenshot, there are many tabs in pull-down tab list (almost all are Huffington post) that have dot spinner on them -- it never goes away. This mostly due to Faecbook conversations plug-in is not getting loaded. This may be or mat not be related to anything, I am writing it just in case.

Initially I thought that this spinner issue could be related to this bug or to #bug 1185667, but, of course, I am not sure.
Important addition: 

Second Plugin container, that was 1.7 GB, occupied 11% of my CPU resources, which is equivalent of nearly 90% of one virtual core (I have 4 real cores, 8 virtual ones in Intel i7-3770). 

As soon as I manually killed this process via task manager, the spinner issue was gone, as wall as dot-spinners on Huffington Post tabs in pull-down menu -- now tabs have message about that Adobe Flash plugin has crashed. So, as it turns out, main culprit for the spinner was this ancient evil, Adobe Flash.

_______________________________________________________________

BUT FireFox is still not stabily snappy: every 20-30 seconds or so main plugin-container's CPU usage slowly raises from 3-4% of all CPU resources to peak 15%, which means equivalent of full virtual core (12.5%) and then some portion of another virtual core (the rest 2.5%). In this moment text I am typing does not show up on screen for a second or two. This peak is marked with red in the attached screenshot.

I have one video running in one of tabs in the background, but it provides constant CPU load. So the culprit this time is probably clog of grouped background JS scripts that pile up periodically to degree that makes UI unresponsive.

I thought that whole point of Electrolysis that this should not be possible. Should be there changes to this architecture that would not allow any number of background JS scripts to pile up and clog things to degree that shortly freezes FireFox even in e10s with Safe mode?
(In reply to User Dderss from comment #31)
> Created attachment 8718456 [details]
> FireFox 45b4 e10s in safe mode -- peak CPU uses makes it unresponsive for a
> second or two.png
> 
> Important addition: 
> 
> Second Plugin container, that was 1.7 GB, occupied 11% of my CPU resources,
> which is equivalent of nearly 90% of one virtual core (I have 4 real cores,
> 8 virtual ones in Intel i7-3770). 
> 
> As soon as I manually killed this process via task manager, the spinner
> issue was gone, as wall as dot-spinners on Huffington Post tabs in pull-down
> menu -- now tabs have message about that Adobe Flash plugin has crashed. So,
> as it turns out, main culprit for the spinner was this ancient evil, Adobe
> Flash.
> 
> _______________________________________________________________
> 
> BUT FireFox is still not stabily snappy: every 20-30 seconds or so main
> plugin-container's CPU usage slowly raises from 3-4% of all CPU resources to
> peak 15%, which means equivalent of full virtual core (12.5%) and then some
> portion of another virtual core (the rest 2.5%). In this moment text I am
> typing does not show up on screen for a second or two. This peak is marked
> with red in the attached screenshot.
> 
> I have one video running in one of tabs in the background, but it provides
> constant CPU load. So the culprit this time is probably clog of grouped
> background JS scripts that pile up periodically to degree that makes UI
> unresponsive.
> 
> I thought that whole point of Electrolysis that this should not be possible.

During that time, was the _browser UI_ unresponsive? Or just the web content UI?

Part of the point of e10s is to prevent such things from making the browser UI unresponsive. It is not a goal for e10s to improve page response times.
Flags: needinfo?(zxspectrum3579)
(In reply to Mike Conley (:mconley) - Needinfo me! from comment #32)
> During that time, was the _browser UI_ unresponsive? Or just the web content
> UI?
> 
> Part of the point of e10s is to prevent such things from making the browser
> UI unresponsive. It is not a goal for e10s to improve page response times.

It was UI freeze, page itself (this one, bugzilla.mozilla.org) does not do a thing with comment window where I typed my comment and got those one-two second freezes of any cursor or typing action to be displayed/rendered. Keyboard and mouse input was listening, so all of my actions eventually did took place, but all of it only got displayed after such short freeze.

_______________________________________________________________

By the way, there is another related mystery: main plugin container (tabs) that was initially 3 GB and slowly grew to 4 GB (as mentioned in comment #30) by this time grew another 400 GB to 4.4 GB -- even after I closed tab with HTML5 video that was played in background.

During this whole time no new tabs were opened/activated, and yet 1.4 GB growth occurred!

Does this mean that not only some background JS scripts cause clogs/periodic short freezes of UI of FF 45b4 with e10s even under Safe mode, but they also generate/accumulate giant amount of junk that slowly but surely and noticeably piles up forever?
Flags: needinfo?(zxspectrum3579)
I see the spinner all the time when dom.ipc.processCount is set to >1.
If it's set to 1 I rarely see it, and when it shows up then only for a fraction of a second.
As I understand dom.ipc.processCount>1 isn't supported yet, so you should expect issues with it.
Addition to comment #33: what is also annoying is that FireFox with e10s on in SafeMode after some of UI freezes jumps in the task bar from the middle to the very right.

I guess this happens when Window's explorer.exe thinks that application is almost dead in terms of UI, but then application revives and it gets restored in task bar, though not in original position, but as newly opened application -- hence it is on the very right.
all sub bugs tracked under e10s-perf, dropping this from our lists.
Priority: P2 → --
Summary: [e10s] switching tabs can sometimes wait a long time for pages to render → [e10s] tracking bug for page render times when switching tabs
Depends on: 1345516
Severity: normal → S3

The severity field for this bug is relatively low, S3. However, the bug has 19 votes.
:gw280, could you consider increasing the bug severity?

For more information, please visit auto_nag documentation.

Flags: needinfo?(gw)
Severity: S3 → --
Type: defect → task
Flags: needinfo?(gw)
Keywords: meta
Summary: [e10s] tracking bug for page render times when switching tabs → [meta] [e10s] tracking bug for page render times when switching tabs

The bug assignee is inactive on Bugzilla, so the assignee is being reset.

Assignee: gw → nobody

Inactive metabug

Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.