1118689 - [non-e10s] 100% CPU usage even if opened a blank tab only and browser process remains on exit

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[Alice0775 White]

[Tracking Requested - why for this release]: Browser hang up

This problem happens with/without Flash Plugin, with/without e10s.

Reproducible: always

Steps To Reproduce:
1. Open a topic of http://game.watch.impress.co.jp/backno/news/index.html in Tab[1]
2. Reload the tab (F5) until CPU usage becomes 100% core
   maybe it needs at least 5-10times
   --- Browser hangs here sometimes
3. Open blank tab in Tab[2]
4. Close tab [1]
   --- 100% core forever.
5. Exit Browser 
   --- firefox.exe remains in process list forever

Actual Results:
100% core forever.
http://people.mozilla.org/~bgirard/cleopatra/#report=cb475cb8b8ecee36eeec26c2d4aefd3472509286
And after exit browser, firefox.exe remains in process list forever.

And browser becomes unresponsive completely sometimes.


Expected Results:
Browser should not hang up.
Should CPU utilization settle to 0%.
Process should disappear immediately after quit.

Comment 1

[Alice0775 White]

bp-65d92e0b-a90a-412b-ae4d-4492d2150107

Comment 2

[Alice0775 White]

bp-6299e38b-173d-4fa2-ac7f-9f3cd2150107

Comment 3

[Alice0775 White]

Attachment: Bug1118689.zip for the record( it needs network access to reproduce the problem )

Comment 4

[Alice0775 White]

Steps
1. Open index.html of attachment 8545237 [details] in Tab[1] (network access should be available)
2. Wait for a while so that CPU usage becomes almost 100% core
3. Open about:blank in new tab Tab[2]
4. Close tab [1]
   ---- observe CPU still high usage --- Bug!
5. Close Browser
   ---- observe CPU still high usage and process remains --- also Bug!

Regression window(m-c)
Good:
https://hg.mozilla.org/mozilla-central/rev/201feeaf31f3
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0 ID:20140323082913
Bad:
https://hg.mozilla.org/mozilla-central/rev/b1b18e742a42
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0 ID:20140323171514
Pushlog:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=201feeaf31f3&tochange=b1b18e742a42


Regression window(m-i)
Good:
https://hg.mozilla.org/integration/mozilla-inbound/rev/0f161bf4f415
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0 ID:20140323084414
Bad:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e15020347f1b
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Firefox/31.0 ID:20140323085513
Pushlog:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=0f161bf4f415&tochange=e15020347f1b

regressed by: Bug 986542

Comment 5

[Sylvestre Ledru [:Sylvestre]]

We have this regression for a while. I don't think we will do a new 35 build for this.
However, if the patch is low risk, we will be happy to take a fix for 36.

Comment 6

[Bobby Holley (:bholley)]

Boris, do you have time to look at this?

Comment 7

[Alice0775 White]

Attachment: google_ad.zip ( This is the culprit )

Comment 8

[Boris Zbarsky [:bzbarsky]]

I can't seem to reproduce the bug, at least in a trunk debug build on Mac...  In particular, loading the index.html from the attached zip file never sends CPU to 100% after the pageload finishes. :(

I'll attach the patch I was going to use to debug this.  If someone can reproduce this in their own build, it would be interesting to set a breakpoint in nsScriptSecurityManager::ScriptAllowed right before the return statement, condition it on "thingie.mDetached" being true, and see whether it's getting hit repeatedly after the 100% CPU tab has been closed.  If so, it would be interesting to know what the C++ callstack looks like at that point, and which JS function we're about to call via the callback object we have in the parent frame's CallbackObject code.

Comment 9

[Boris Zbarsky [:bzbarsky]]

Attachment: Debugging patch

Comment 10

[Olli Pettay [:smaug][[e-mail]]]

I can't reproduce on linux (opt build).

Comment 11

[Alice0775 White]

I can reproduce on Ubuntu14.04 64bit too.

https://hg.mozilla.org/mozilla-central/rev/2a193b7f395c
Mozilla/5.0 (X11; Linux x86_64; rv:37.0) Gecko/20100101 Firefox/37.0 ID:20150106030201

So, The Google ad seems to be limited in Japan region... :(

Comment 12

[Alice0775 White]

I should mention that the problem does not occur in e10s window.

Comment 13

[Alice0775 White]

Boris Zbarsky [:bz]
Olli Pettay [:smaug]

Could you test once with non-e10s window?

Comment 14

[Boris Zbarsky [:bzbarsky]]

The testing I did in comment 8 was with a non-e10s window.

Comment 15

[Olli Pettay [:smaug][[e-mail]]]

I was testing non-e10s too.

Comment 16

[Alice0775 White]

Attachment: index_1.html minimum, expired :(

Comment 17

[Alice0775 White]

I think this should be fixed in high priority because Google ad codes causes the problem.

(Unfortunately, this maybe the region limited problem. and also I do not familiar windbg/gdb...)

Comment 18

[Olli Pettay [:smaug][[e-mail]]]

Alice, is the cleopatra profile created using Nightly? If not, could you use Nightly 
(stackwalking enabled for the profiling).

Comment 19

[Olli Pettay [:smaug][[e-mail]]]

Masayuki, do you know if anyone from Mozilla Japan could help with this a bit.

Comment 20

[Alice0775 White]

Profilering from Step1 to Step2 in comment#4
http://people.mozilla.org/~bgirard/cleopatra/#report=0d03080074cebb2533e7451dcb279b458727277f

Profilering after Step4
http://people.mozilla.org/~bgirard/cleopatra/#report=871468801a709a7ecda2c7778591f261670565bc

Comment 21

[Alice0775 White]

attachment 8545445 [details] is expired.

Comment 22

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Hmm, I've never experienced this and all of them are expired...

Comment 23

[Alice0775 White]

[Tracking Requested - why for this release]:

Reproduced on https://mixi.jp/

Comment 24

[Alice0775 White]

The problem happens when the following Google ads is shown.
"ブランド高く売れる"
"車高く売れる"

And the ad seems to go is spread widely on famous site in Japan.

Comment 25

[Olli Pettay [:smaug][[e-mail]]]

Need some help here.

Does Mozilla Japan happen to have a VPN to use?

Comment 26

[Masatoshi Kimura [:emk]]

I have never worked at Mozilla Japan.

Comment 27

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

(In reply to Olli Pettay [:smaug] from comment #25)
> Need some help here.
> 
> Does Mozilla Japan happen to have a VPN to use?

Kato-san?

Comment 28

[Olli Pettay [:smaug][[e-mail]]]

Sorry Masatoshi, my comment wasn't clear.
 I was wondering if you could help here, like reproduce this (and Masayuki might know whether there is a VPN).

Comment 29

[Makoto Kato [:m_kato]]

(In reply to Masayuki Nakano (:masayuki) (Mozilla Japan) from comment #27)
> (In reply to Olli Pettay [:smaug] from comment #25)
> > Need some help here.
> > 
> > Does Mozilla Japan happen to have a VPN to use?
> 
> Kato-san?

I don't have VPN for MV.  But maybe, I can setup proxy.

Comment 30

[Makoto Kato [:m_kato]]

I cannot reproduce by https://mixi.jp/ or http://game.watch.impress.co.jp/backno/news/index.html now...

Comment 31

[Alice0775 White]

No longer seeing these ads.

Comment 32

[Sylvestre Ledru [:Sylvestre]]

Stop tracking then.

Comment 33

[Masaki Ishido]

I have might-be-same issue.  In my case advertising on issue is delivered by doubleclick.net.  URL of the ad are

https://ad.doubleclick.net/adi/N7586.150834.TURN/B8186874.109993605;sz=728x90;ord=%5Btimestamp%5D?:89

and

https://ad.doubleclick.net/adi/N7586.150834.TURN/B8186874.109993604;sz=300x250;ord=%5Btimestamp%5D?:89

Reproduced on Japanese version of35.0.1, 37.0a2 (2015-01-29) and 38.0a1 (2015-01-29).

Comment 34

[Alice0775 White]

I can reproduce with the URLs in Comment#33. And get same regression window of comment#4 .

The problem advertising seems to have spread widely.

:bz
Can you reproduce with the URLs in Comment#33?

Comment 35

[Boris Zbarsky [:bzbarsky]]

Yes, thank you.  Using the second of those urls, in non-e10s mode, I see the 100% CPU usage and the failure to quit.  Looking into it.

Comment 36

[Boris Zbarsky [:bzbarsky]]

OK, so while we're running the page, everything is dandy as far as I can tell.

When I try to quit (in non-e10s mode), we end up in a loop running "load" events.  The load event runs the .prototype<.handleLoad_.value function in <https://ad.doubleclick.net/adi/N7586.150834.TURN/B8186874.109993604;sz=300x250;ord=%5Btimestamp%5D?:89> which in turn runs  .prototype<.applyScaling_.value in the same file.

This sets the "src" attribute on the <img>, which then fires another load event, etc.

So the real issue here is that we don't really have a distinction between "<browser> removed from the DOM because we're quitting" and "<iframe> removed from the DOM because web page".  Bug 986542 made events work in the latter case, but this quit case looks identical from Gecko's point of view.  So we end up in a situation where the mainthread event loop never empties out and shutdown can't proceed.

Here's a trivial testcase that has this behavior:

  data:text/html,<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP" onload="this.src = this.src">

If I load this and then quit the browser (still in non-e10s mode), I get the shutdown hang (well, until the MOZ_CRASH from RunWatchdog kicks in) with 100% CPU usage.

Olli, any thoughts on how we should handle this?  We really need to figure out when we can just mark windows as "no more execution here, please".

Comment 37

[Olli Pettay [:smaug][[e-mail]]]

Does img.src = img.src need to do anything when the relevant docshell has been detached?
That feels like a simpler thing to fix than trying to figure out when
an event listener shouldn't be called anymore (since we don't want to regress Bug 986542).

Comment 38

[Boris Zbarsky [:bzbarsky]]

> Does img.src = img.src need to do anything when the relevant docshell has been detached?

I don't know...  We could try simply bailing out of LoadImage if we're in such a situation.  We _do_ need to do it for image elements in data documents that never had a window, though maybe not if the global they're associated with has been detached...

Comment 39

[Olli Pettay [:smaug][[e-mail]]]

What do you mean with "though maybe not if the global they're associated with has been detached..."

Comment 40

[Boris Zbarsky [:bzbarsky]]

Actually, I was just confused.  Images in data documents never perform loads anyway.

Comment 41

[Olli Pettay [:smaug][[e-mail]]]

Attachment: v1

Not super pretty. Tried to reduce risk for regressions, so didn't change
data or chrome document handling.

https://tbpl.mozilla.org/?tree=Try&rev=d99242b0bf0f

Comment 42

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 8563586 [details] [diff] [review]
v1

> nsImageLoadingContent::SetLoadingEnabled(bool aLoadingEnabled)

Seems to me like setting false should be allowed even if our document (currently) can't load images.  So like so:

  mLoadingEnabled = aLoadingEnabled && nsContentUtils::GetImgLoaderForChannel(nullptr, GetOurOwnerDoc());

though this does mean you can't reenable loading for an <img> that's bfcached before it comes out of bfcache....

Do we really need to condition mLoadingEnabled on the document state at all?

> nsImageLoadingContent::FireEvent(const nsAString& aEventType)

Why is the change here needed?  This one seems a bit odd...  I guess the problem is error events?  Worth documenting.

r=me modulo the above.

Comment 43

[Olli Pettay [:smaug][[e-mail]]]

mLoadingEnabled is indeed very odd, and didn't want to change its behavior.

The FireEvent case is there because there are code paths where we end up firing error event if
LoadImage and such calls fail. I'll add a comment.

Comment 44

[Boris Zbarsky [:bzbarsky]]

> mLoadingEnabled is indeed very odd, and didn't want to change its behavior.

Then please don't?

The current mLoadingEnabled behavior is that it's set based on whether image loading is enabled at all.  Then if image loading is globally disabled, you can't toggle mLoadingEnabled.  Just leave that behavior instead of introducing dependencies on the document.

Comment 45

[Olli Pettay [:smaug][[e-mail]]]

Oh, crap, I had the constructor in my mind, not the setter. Will pass nullptr also in setter.

Comment 46

[Olli Pettay [:smaug][[e-mail]]]

Attachment: v2

But need to wait for tryserver results before landing.

Comment 47

[Olli Pettay [:smaug][[e-mail]]]

Looks like I need to still enable stuff for svg images.

Comment 48

[Olli Pettay [:smaug][[e-mail]]]

Attachment: v3

https://tbpl.mozilla.org/?tree=Try&rev=86a65ceaddd2

Comment 49

[Olli Pettay [:smaug][[e-mail]]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/19bb3d54cafe

Comment 50

[Olli Pettay [:smaug][[e-mail]]]

[Tracking Requested - why for this release]:
100% cpu usage is bad.

Need to get some feedback for the new behavior, so fixing this for FF36 might not be a good idea, 
but FF37 perhaps.

Comment 51

[Sylvestre Ledru [:Sylvestre]]

Too late for 36.
However, Smaug, could you fill an uplift request for aurora?
Thanks

Comment 52

[Olli Pettay [:smaug][[e-mail]]]

Comment on attachment 8563715 [details] [diff] [review]
v3

Approval Request Comment
[Feature/regressing bug #]:bug 986542
[User impact if declined]: High cpu usage
[Describe test coverage new/current, TreeHerder]: landed with a test.
[Risks and why]: not very risky. It does prevent images to load in certain cases when web pages are going away, so if some web site relies on such behavior...
[String/UUID change made/needed]:NA

Comment 53

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/19bb3d54cafe

Comment 54

[Lawrence Mandel [:lmandel] (use needinfo)]

(In reply to Olli Pettay [:smaug] from comment #52)
> [Risks and why]: not very risky. It does prevent images to load in certain
> cases when web pages are going away, so if some web site relies on such
> behavior...

Do you understand these cases and can you provide more specifics?

Alice - Can you still reproduce on the latest Nightly build?

Comment 55

[Alice0775 White]

I can not the problem on the following Nightly38.0a1.

https://hg.mozilla.org/mozilla-central/rev/09f4968d5f42
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:38.0) Gecko/20100101 Firefox/38.0 ID:20150217030213


However, I can still reproduce the problem on the following Aurora37.0a2 and Beta36.0b9.

https://hg.mozilla.org/releases/mozilla-aurora/rev/997fae1e1f88
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firefox/37.0 ID:20150217004007

https://hg.mozilla.org/releases/mozilla-beta/rev/101d05cb5635
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:36.0) Gecko/20100101 Firefox/36.0 ID:20150212154903

Comment 56

[Olli Pettay [:smaug][[e-mail]]]

(In reply to Lawrence Mandel [:lmandel] (use needinfo) from comment #54)
> (In reply to Olli Pettay [:smaug] from comment #52)
> Do you understand these cases and can you provide more specifics?
From comment 36
data:text/html,<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP" onload="this.src = this.src">

So yes, we understand pretty well how this can happen and why the regression happened.

Comment 57

[Lawrence Mandel [:lmandel] (use needinfo)]

Comment on attachment 8563715 [details] [diff] [review]
v3

Thanks for verifying. Aurora+

Comment 58

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/878a4115c0b6