Last Comment Bug 532730 - ###!!! ASSERTION: Caller forgot to check ReadyToExecuteScripts()
: ###!!! ASSERTION: Caller forgot to check ReadyToExecuteScripts()
Status: RESOLVED FIXED
[3.6.x][sg:critical?][critsmash:resol...
: regression, testcase, verified1.9.2
Product: Core
Classification: Components
Component: DOM: Core & HTML (show other bugs)
: Trunk
: All All
: -- critical (vote)
: ---
Assigned To: Blake Kaplan (:mrbkap)
:
Mentors:
Depends on: 594699
Blocks:
  Show dependency treegraph
 
Reported: 2009-12-03 12:49 PST by Jason Oster (:Parasyte)
Modified: 2010-09-27 18:18 PDT (History)
14 users (show)
mbeltzner: blocking1.9.2-
mbeltzner: wanted1.9.2+
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
beta1+
.9+
.9-fixed
.12+
.12-fixed


Attachments
Simple backtrace (53.86 KB, text/plain)
2009-12-03 12:50 PST, Jason Oster (:Parasyte)
no flags Details
Test-case include (48 bytes, application/javascript)
2009-12-04 06:50 PST, Jason Oster (:Parasyte)
no flags Details
Test-case (928 bytes, text/html)
2009-12-04 06:52 PST, Jason Oster (:Parasyte)
no flags Details
full backtrace (183.89 KB, text/plain)
2009-12-17 14:06 PST, Jason Oster (:Parasyte)
no flags Details
Proposed fix (1.28 KB, patch)
2010-04-21 17:59 PDT, Blake Kaplan (:mrbkap)
jst: review+
jonas: superreview+
christian: approval1.9.2.9-
Details | Diff | Splinter Review
Better fix (9.44 KB, patch)
2010-04-23 20:32 PDT, Blake Kaplan (:mrbkap)
jonas: superreview-
Details | Diff | Splinter Review
Better better fix (9.41 KB, patch)
2010-04-27 15:54 PDT, Blake Kaplan (:mrbkap)
jst: review+
jonas: superreview+
christian: approval1.9.2.9+
christian: approval1.9.1.12+
Details | Diff | Splinter Review

Description Jason Oster (:Parasyte) 2009-12-03 12:49:39 PST
User-Agent:       Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.7pre) Gecko/20091203 Shiretoko/3.5.7pre
Build Identifier: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.7pre) Gecko/20091203 Shiretoko/3.5.7pre

While trying to get a website working with Firefox (using Greasemonkey to inject proper JavaScript -- the whole site is written with IE6-specific gunk) I ran into a problem where Firefox deadlocks attempting to run scripts on the page.

Unfortunately, the website in question is the HR site for my employer.  I'm unable to provide credentials for login.  I'll try to get a local copy of the HTML+Scripts, just to see if I can reproduce the deadlock without logging into the actual server.

I built Firefox from mozilla-1.9.1 repository today with debugging symbols enabled and loaded it into GDB.  There is a spew of console output, the following lines repeated indefinitely:

> ###!!! ASSERTION: Caller forgot to check ReadyToExecuteScripts(): 'ReadyToExecuteScripts() && nsContentUtils::IsSafeToRunScript()', file /home/osterj/other-projects/mozilla-1.9.1/content/base/src/nsScriptLoader.cpp, line 585
> ###!!! ASSERTION: Inner window detected in Equality hook!: 'win->IsOuterWindow()', file /home/osterj/other-projects/mozilla-1.9.1/dom/src/base/nsDOMClassInfo.cpp, line 6653
> ###!!! ASSERTION: Inner window detected in Equality hook!: 'other->IsOuterWindow()', file /home/osterj/other-projects/mozilla-1.9.1/dom/src/base/nsDOMClassInfo.cpp, line 6659

At some point, the "Unresponsive Script" dialog opens, but it is completely empty.  The dialog contains no controls (!) and sometimes even no title. The assertion spews in the console are still dumping at this point.  -> Mandatory kill.

I have a simple backtrace from halting the process during the assertion spew.  Will attach.

Reproducible: Always
Comment 1 Jason Oster (:Parasyte) 2009-12-03 12:50:49 PST
Created attachment 415936 [details]
Simple backtrace
Comment 2 Jason Oster (:Parasyte) 2009-12-04 06:50:35 PST
Created attachment 416084 [details]
Test-case include
Comment 3 Jason Oster (:Parasyte) 2009-12-04 06:52:55 PST
Created attachment 416085 [details]
Test-case

I've created a reduced test-case.  There is a programming error in the website's JavaScript; it reuses a variable for iteration within nested loops.  (Somehow, this works on IE ...?)  This bug manifests as a result of DOM modification within an infinite loop.

This can be seen in my test case (where I intentionally duplicate this programming error) at lines 19 and 28.

Be careful with this attachment; it is a very effective DoS.
Comment 4 Jason Oster (:Parasyte) 2009-12-09 07:50:33 PST
This is a regression; the 3.0 tree is unaffected.
Comment 5 Mike Beltzner [:beltzner, not reading bugmail] 2009-12-14 20:52:08 PST
Thanks for the testcase; I think it's too late for this to hit the final release of Firefox 3.6, but I've marked it for one of the security and stability releases, and for the next product release.

Roc/David: over to you!
Comment 6 Johnny Stenback (:jst, jst@mozilla.com) 2009-12-15 19:35:10 PST
Jonas, could you have a first look at this? The first assertion in comment 0 is "Caller forgot to check ReadyToExecuteScripts()" in nsScriptLoader, and then stuff that probably isn't in your ballpark after that, but maybe the script loader gets confused somehow and triggers other bad things here?
Comment 7 Johnny Stenback (:jst, jst@mozilla.com) 2009-12-15 19:35:51 PST
And yes, this sounds pretty bad, but given that it's in 1.9.1 as well, I don't think we need to block 1.9.2 on this at this point.
Comment 8 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-16 14:28:36 PST
Doesn't seem to reproduce on trunk. Building a 1.9.1 tree right now to see if i can reproduce there.
Comment 9 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-16 18:08:43 PST
Jason: Can you reproduce this using the bugzilla attachment?

I can only seem to reproduce if I download the testcase locally (and modify the html file to point to the js file).

It also seems to require turning off the popup blocker.
Comment 10 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-16 18:10:17 PST
When loading from file, I get a slightly different assertion at the below stack. The scary thing here is that AsyncOpen causes script to execute!

#3  0x003d510c in Break (aMsg=0xbfff88d0 "###!!! ASSERTION: This is unsafe: 'nsContentUtils::IsSafeToRunScript()', file /Users/sicking/trees/191/src/layout/base/nsDocumentViewer.cpp, line 1081") at /Users/sicking/trees/191/src/xpcom/base/nsDebugImpl.cpp:485
#4  0x003d57a2 in NS_DebugBreak_P (aSeverity=1, aStr=0x142c04c0 "This is unsafe", aExpr=0x142c049c "nsContentUtils::IsSafeToRunScript()", aFile=0x142bf878 "/Users/sicking/trees/191/src/layout/base/nsDocumentViewer.cpp", aLine=1081) at /Users/sicking/trees/191/src/xpcom/base/nsDebugImpl.cpp:364
#5  0x1399ea1e in DocumentViewerImpl::PermitUnload (this=0x183192e0, aPermitUnload=0xbfff8fd8) at /Users/sicking/trees/191/src/layout/base/nsDocumentViewer.cpp:1081
#6  0x1526c1a0 in nsDocShell::InternalLoad (this=0x25729600, aURI=0x1831fb10, aReferrer=0x20f8b340, aOwner=0x1e6591c0, aFlags=8, aWindowTarget=0x1831ad70, aTypeHint=0x0, aPostData=0x0, aHeadersData=0x0, aLoadType=1, aSHEntry=0x0, aFirstParty=1, aDocShell=0x0, aRequest=0x0) at /Users/sicking/trees/191/src/docshell/base/nsDocShell.cpp:7402
#7  0x152655d9 in nsDocShell::LoadURI (this=0x25729600, aURI=0x1831fb10, aLoadInfo=0x18312350, aLoadFlags=16384, aFirstParty=1) at /Users/sicking/trees/191/src/docshell/base/nsDocShell.cpp:963
#8  0x13680bed in nsWindowWatcher::OpenWindowJSInternal (this=0x182c570, aParent=0x1ca17890, aUrl=0x136c84ac "chrome://global/content/commonDialog.xul", aName=0x136c7f18 "_blank", aFeatures=0x136c8260 "centerscreen,chrome,modal,titlebar", aDialog=1, argv=0x1831fac0, aCalledFromJS=0, _retval=0xbfff972c) at /Users/sicking/trees/191/src/embedding/components/windowwatcher/src/nsWindowWatcher.cpp:929
#9  0x136817d2 in nsWindowWatcher::OpenWindow (this=0x182c570, aParent=0x1ca17890, aUrl=0x136c84ac "chrome://global/content/commonDialog.xul", aName=0x136c7f18 "_blank", aFeatures=0x136c8260 "centerscreen,chrome,modal,titlebar", aArguments=0x183202e0, _retval=0xbfff972c) at /Users/sicking/trees/191/src/embedding/components/windowwatcher/src/nsWindowWatcher.cpp:422
#10 0x1368b181 in nsPromptService::DoDialog (this=0x1c2c0a00, aParent=0x1ca17890, aParamBlock=0x183202e0, aChromeURL=0x136c84ac "chrome://global/content/commonDialog.xul") at /Users/sicking/trees/191/src/embedding/components/windowwatcher/src/nsPromptService.cpp:786
#11 0x1368bb36 in nsPromptService::ConfirmEx (this=0x1c2c0a00, parent=0x1ca17890, dialogTitle=0x18320e20, text=0x86d808, buttonFlags=0, button0Title=0x18320e60, button1Title=0x18320e80, button2Title=0x18320ed0, checkMsg=0x18320ea0, checkValue=0xbfff9ae0, buttonPressed=0xbfff9ae4) at /Users/sicking/trees/191/src/embedding/components/windowwatcher/src/nsPromptService.cpp:397
#12 0x13674f3d in nsPrompt::ConfirmEx (this=0x18320da0, dialogTitle=0x18320e20, text=0x86d808, buttonFlags=8355711, button0Title=0x18320e60, button1Title=0x18320e80, button2Title=0x18320ed0, checkMsg=0x18320ea0, checkValue=0xbfff9ae0, buttonPressed=0xbfff9ae4) at /Users/sicking/trees/191/src/embedding/components/windowwatcher/src/nsPrompt.cpp:243
#13 0x13f1d4c5 in nsJSContext::DOMOperationCallback (cx=0x12fec00) at /Users/sicking/trees/191/src/dom/src/base/nsJSEnvironment.cpp:1139
#14 0x000dd6eb in js_InvokeOperationCallback (cx=0x12fec00) at /Users/sicking/trees/191/src/js/src/jscntxt.cpp:1755
#15 0x0011d49c in js_Interpret (cx=0x12fec00) at /Users/sicking/trees/191/src/js/src/jsinterp.cpp:3161
#16 0x0014b85e in js_Invoke (cx=0x12fec00, argc=0, vp=0x171d93c, flags=0) at jsinterp.cpp:1394
#17 0x0014be8d in js_InternalInvoke (cx=0x12fec00, obj=0x17b76d40, fval=397895520, flags=0, argc=0, argv=0x0, rval=0xbfffadd4) at jsinterp.cpp:1447
#18 0x0014c105 in js_InternalGetOrSet (cx=0x12fec00, obj=0x17b76d40, id=324319668, fval=397895520, mode=JSACC_READ, argc=0, argv=0x0, rval=0xbfffadd4) at jsinterp.cpp:1510
#19 0x0015e57f in js_GetSprop (cx=0x12fec00, sprop=0x144f2f0, obj=0x17b76d40, vp=0xbfffadd4) at jsscope.h:367
#20 0x0016026f in js_NativeGet (cx=0x12fec00, obj=0x17b76d40, pobj=0x17b761a0, sprop=0x144f2f0, vp=0xbfffadd4) at /Users/sicking/trees/191/src/js/src/jsobj.cpp:4167
#21 0x0012fbe0 in js_Interpret (cx=0x12fec00) at /Users/sicking/trees/191/src/js/src/jsinterp.cpp:4436
#22 0x0014b85e in js_Invoke (cx=0x12fec00, argc=1, vp=0x171d86c, flags=0) at jsinterp.cpp:1394
#23 0x11deabd3 in nsXPCWrappedJSClass::CallMethod (this=0x1def47f0, wrapper=0x1de87040, methodIndex=8, info=0x22803888, nativeParams=0xbfffb278) at /Users/sicking/trees/191/src/js/src/xpconnect/src/xpcwrappedjsclass.cpp:1697
#24 0x11de1851 in nsXPCWrappedJS::CallMethod (this=0x1de87040, methodIndex=8, info=0x22803888, params=0xbfffb278) at /Users/sicking/trees/191/src/js/src/xpconnect/src/xpcwrappedjs.cpp:569
#25 0x003e6b22 in PrepareAndDispatch (self=0x1def48a0, methodIndex=8, args=0xbfffb394) at /Users/sicking/trees/191/src/xpcom/reflect/xptcall/src/md/unix/xptcstubs_unixish_x86.cpp:93
#26 0x003e1805 in nsXPTCStubBase::Stub8 (this=0x1def48a0) at xptcstubsdef.inc:6
#27 0x152af9f4 in nsExternalHelperAppService::GetTypeFromExtension (this=0x75bf10, aFileExt=@0xbfffb598, aContentType=@0xbfffb718) at /Users/sicking/trees/191/src/uriloader/exthandler/nsExternalHelperAppService.cpp:2588
#28 0x152aeca1 in nsExternalHelperAppService::GetTypeFromFile (this=0x75bf10, aFile=0x18320d80, aContentType=@0xbfffb718) at /Users/sicking/trees/191/src/uriloader/exthandler/nsExternalHelperAppService.cpp:2749
#29 0x1209aee8 in nsFileChannel::MakeFileInputStream (this=0x18320ad0, file=0x18320d80, stream=@0xbfffb6f4, contentType=@0xbfffb718) at /Users/sicking/trees/191/src/netwerk/protocol/file/src/nsFileChannel.cpp:302
#30 0x1209b43f in nsFileChannel::OpenContentStream (this=0x18320ad0, async=1, result=0xbfffb7ec, channel=0xbfffb7e8) at /Users/sicking/trees/191/src/netwerk/protocol/file/src/nsFileChannel.cpp:371
#31 0x11fdfb71 in nsBaseChannel::BeginPumpingData (this=0x18320ad0) at /Users/sicking/trees/191/src/netwerk/base/src/nsBaseChannel.cpp:227
#32 0x11fdff28 in nsBaseChannel::AsyncOpen (this=0x18320ad0, listener=0x18320cf0, ctxt=0x18321700) at /Users/sicking/trees/191/src/netwerk/base/src/nsBaseChannel.cpp:546
#33 0x13ce74f5 in nsScriptLoader::StartLoad (this=0x1e64eee0, aRequest=0x18321700, aType=@0xbfffbb7c) at /Users/sicking/trees/191/src/content/base/src/nsScriptLoader.cpp:290
#34 0x13ce8a8b in nsScriptLoader::ProcessScriptElement (this=0x1e64eee0, aElement=0x18321ed4) at /Users/sicking/trees/191/src/content/base/src/nsScriptLoader.cpp:543
#35 0x13ce4399 in nsScriptElement::MaybeProcessScript (this=0x18321ed4) at /Users/sicking/trees/191/src/content/base/src/nsScriptElement.cpp:193
#36 0x13dbd20f in nsHTMLScriptElement::MaybeProcessScript (this=0x18321eb0) at /Users/sicking/trees/191/src/content/html/content/src/nsHTMLScriptElement.cpp:546
#37 0x13dbbf6f in nsHTMLScriptElement::BindToTree (this=0x18321eb0, aDocument=0x176de00, aParent=0x1cd92c90, aBindingParent=0x0, aCompileEventHandlers=1) at /Users/sicking/trees/191/src/content/html/content/src/nsHTMLScriptElement.cpp:415
#38 0x13cadff7 in nsGenericElement::doInsertChildAt (aKid=0x18321eb0, aIndex=12068, aNotify=1, aParent=0x1cd92c90, aDocument=0x176de00, aChildArray=@0x1cd92cac) at /Users/sicking/trees/191/src/content/base/src/nsGenericElement.cpp:3258
#39 0x13cae255 in nsGenericElement::InsertChildAt (this=0x1cd92c90, aKid=0x18321eb0, aIndex=12068, aNotify=1) at /Users/sicking/trees/191/src/content/base/src/nsGenericElement.cpp:3203
#40 0x13cad356 in nsGenericElement::doReplaceOrInsertBefore (aReplace=0, aNewChild=0x18321ed0, aRefChild=0x0, aParent=0x1cd92c90, aDocument=0x176de00, aReturn=0xbfffc23c) at /Users/sicking/trees/191/src/content/base/src/nsGenericElement.cpp:3948
#41 0x13cad4b5 in nsGenericElement::InsertBefore (this=0x1cd92c90, aNewChild=0x18321ed0, aRefChild=0x0, aReturn=0xbfffc23c) at /Users/sicking/trees/191/src/content/base/src/nsGenericElement.cpp:3522
#42 0x13d7fb5a in nsHTMLBodyElement::InsertBefore (this=0x1cd92c90, newChild=0x18321ed0, refChild=0x0, _retval=0xbfffc23c) at /Users/sicking/trees/191/src/content/html/content/src/nsHTMLBodyElement.cpp:95
Comment 11 Jason Oster (:Parasyte) 2009-12-16 18:17:28 PST
* I'm able to reproduce this from the Bugzilla attachment in FF 3.5.6 release.
* Cannot reproduce it [from the attachment] on my mozilla-central builds. (I haven't tried this build with a local test case.)
* I'll be building the 1.9.2 branch in a short while to test there, as well.

I noticed the different assertions between local file/web content, also.  I attributed it to possible race conditions or similar.  (Not sure about that in the slightest!)  Will report back on further findings.
Comment 12 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-16 18:50:41 PST
If i keep going from that assertion, I'll hit the "Caller forgot to check ReadyToExecuteScripts" assertion right after, with largely the same stack.

So basically what happens is this call chain:

nsGenericElement::InsertBefore -> nsScriptLoader::ProcessScriptElement ->
nsBaseChannel::AsyncOpen

So far so good. AsyncOpen then calls

nsFileChannel::OpenContentStream

And here is where the badness starts. nsFileChannel::OpenContentStream does a bunch of things synchronously. One of which is to (indirectly) call 

nsExternalHelperAppService::GetTypeFromExtension

This function is implemented in javascript. However at this point we've been running page javascript for so long that we end up putting up the slow-script dialog.

While that dialog is open, we spin the event loop which eventually finds a script element that has finished loading and so we attempt to execute it, with the assertion in the summary as result.


So the first bad thing that happens here is that AsyncOpen on the filechannel does so much stuff synchronously, including running script.

The second badness is that we're putting put the slow-script dialog when it's not safe to run script.

It would be easy to make the scriptloader not call AsyncOpen synchronously, however I suspect we in all sorts of places call AsyncOpen not expecting that to spin the eventloop.
Comment 13 Jason Oster (:Parasyte) 2009-12-16 19:31:09 PST
Additional test results:

* Only affects 1.9.2 and m-c when both files are local.
* Affects 1.9.1 locally and served as web content.
Comment 14 Boris Zbarsky [:bz] 2009-12-16 20:58:09 PST
sicking, did you mean to mark this mozilla-corp-confidential?  Or security-sensitive?

> nsFileChannel::OpenContentStream does a bunch of things synchronously

We'd like to make this not get the type sync, but see below.

> This function is implemented in javascript

Uh... no, it's not.  However it looks like someone added an nsIHandlerService that function calls into, and which _is_ implemented in JavaScript.  Looks like that was done in bug 393492.

> However at this point we've been running page javascript for so long that we
> end up putting up the slow-script dialog.

This seems like the real bug to me.  The page js runtime shouldn't affect the chrome JS execution in any way.

> So the first bad thing that happens here is that AsyncOpen on the filechannel
> does so much stuff synchronously, including running script.

You can't stop asyncOpen running script.  Most simply, the whole protocol handler and channel involved can be implemented in JS, no?

> The second badness is that we're putting put the slow-script dialog when it's
> not safe to run script.

I agree that this is a problem.  We should probably suppress it in this case.

> I suspect we in all sorts of places call AsyncOpen not expecting that
> to spin the eventloop.

We've been trying to get rid of such callsites, actually, since asyncOpen also runs progress listeners (often implemented in javascript), etc.  I believe smaug put some work into trying to make sure we only did asyncOpen from script runners in various cases, though there are more to be done.
Comment 15 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-16 22:16:15 PST
> > This function is implemented in javascript
> 
> Uh... no, it's not.  However it looks like someone added an nsIHandlerService
> that function calls into, and which _is_ implemented in JavaScript.  Looks like
> that was done in bug 393492.

Yeah, sorry, i meant to say that it calls something that's implemented in javascript.

> > However at this point we've been running page javascript for so long that we
> > end up putting up the slow-script dialog.
> 
> This seems like the real bug to me.  The page js runtime shouldn't affect the
> chrome JS execution in any way.

I looked in to this with jst a bit. The code for dealing with runtime does so per context and so that part looks fine. The theory is that we end up not being able to grab the correct context to run the component in, and so we reuse the current context. Need to verify this.

> > So the first bad thing that happens here is that AsyncOpen on the filechannel
> > does so much stuff synchronously, including running script.
> 
> You can't stop asyncOpen running script.  Most simply, the whole protocol
> handler and channel involved can be implemented in JS, no?

Indeed. So the question is if we can require such script not to do things that aren't safe to do when there are scriptblockers.

> > The second badness is that we're putting put the slow-script dialog when it's
> > not safe to run script.
> 
> I agree that this is a problem.  We should probably suppress it in this case.

Agreed. Will add this to whatever patch we end up with here.

> > I suspect we in all sorts of places call AsyncOpen not expecting that
> > to spin the eventloop.
> 
> We've been trying to get rid of such callsites, actually, since asyncOpen also
> runs progress listeners (often implemented in javascript), etc.  I believe
> smaug put some work into trying to make sure we only did asyncOpen from script
> runners in various cases, though there are more to be done.

That is pretty unfortunate from a design point of view. Always calling AsyncOpen asynchronously adds a decent amount of complexity. And it shouldn't be needed once we have e10s, right?
Comment 16 Boris Zbarsky [:bz] 2009-12-16 23:53:12 PST
> And it shouldn't be needed once we have e10s, right?

Once it's all done, yeah.
Comment 17 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-17 13:14:31 PST
Jason: If you can reproduce this with a debug build (from any branch) when loading directly from bugzilla, can you attach a full stacktrace for when the "Caller forgot to check..." assertion fires?

And include information about which build was used to create the stacktrace.
Comment 18 Jason Oster (:Parasyte) 2009-12-17 14:06:06 PST
Created attachment 418264 [details]
full backtrace

Jonas: This is a full backtrace from the "forgot to call ReadyToExecuteScripts()" assertion.  Note that this is actually the /fourth/ assertion I get when loading the attachment.  Asserts go in this order:


###!!! ASSERTION: This is unsafe: 'nsContentUtils::IsSafeToRunScript()', file /home/osterj/other-projects/mozilla-1.9.1/layout/base/nsDocumentViewer.cpp, line 1081

###!!! ASSERTION: cannot call GetUsedBorder on a dirty frame not currently being reflowed: 'nsLayoutUtils::sDisableGetUsedXAssertions || !NS_SUBTREE_DIRTY(this) || (GetStateBits() & NS_FRAME_IN_REFLOW)', file /home/osterj/other-projects/mozilla-1.9.1/layout/generic/nsFrame.cpp, line 608

###!!! ASSERTION: cannot call GetUsedBorder on a dirty frame not currently being reflowed: 'nsLayoutUtils::sDisableGetUsedXAssertions || !NS_SUBTREE_DIRTY(this) || (GetStateBits() & NS_FRAME_IN_REFLOW)', file /home/osterj/other-projects/mozilla-1.9.1/layout/generic/nsFrame.cpp, line 608

###!!! ASSERTION: Caller forgot to check ReadyToExecuteScripts(): 'ReadyToExecuteScripts() && nsContentUtils::IsSafeToRunScript()', file /home/osterj/other-projects/mozilla-1.9.1/content/base/src/nsScriptLoader.cpp, line 585


I also grabbed a bt full from that first assertion, if it might be helpful.


$ hg tip
changeset:   26642:ff4253bc919b
tag:         tip
user:        Neil Rashbrook <neil@parkwaycc.co.uk>
date:        Wed Nov 04 21:36:04 2009 +0000
summary:     Bug 524256 Allow the compiler to generate the prologue/epilogue to NS_InvokeByIndex so that it can tell the debugger that it's not omitting frame pointers r=bsmedberg a=ss

$ uname -a
Linux cn212570 2.6.31-16-generic #53-Ubuntu SMP Tue Dec 8 04:02:15 UTC 2009 x86_64 GNU/Linux
Comment 19 Jonas Sicking (:sicking) No longer reading bugmail consistently 2009-12-17 15:20:21 PST
Thanks Jason, that's very helpful!

So essentially the same thing happens. The AsyncOpen call ends up calling into some JS implemented component, and then we time out inside that component.

So I would say the problem is two-fold:

1. We count the time spent in content script towards the time the time for the
   chrome component.
2. We put up the slow-script dialog when it's not safe to run script.

Need to investigate more why 1 is happening.
Comment 20 Brandon Sterne (:bsterne) 2010-02-19 11:00:53 PST
Similar to bug 466057.  Setting as critical.
Comment 21 Johnny Stenback (:jst, jst@mozilla.com) 2010-04-13 15:20:27 PDT
Blake agreed to take this bug from Jonas. His estimate is that this shouldn't be much more than a days worth of work, but has some other stuff ahead of this. His ETA is Tuesday of next week, which is 4/20/2010.
Comment 22 Blake Kaplan (:mrbkap) 2010-04-20 17:51:21 PDT
I'll do this tomorrow.
Comment 23 Blake Kaplan (:mrbkap) 2010-04-21 17:59:12 PDT
Created attachment 440668 [details] [diff] [review]
Proposed fix

This fixes comment 19, point 2. I'll file a separate bug on part 1 of that comment.
Comment 24 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-21 18:15:39 PDT
Comment on attachment 440668 [details] [diff] [review]
Proposed fix

Just make sure to file a followup on blocking any and all modal dialogs while it's not safe to run script.

Also file a followup on making sure we count time toward the correct context.
Comment 25 Blake Kaplan (:mrbkap) 2010-04-21 18:29:10 PDT
Oops, right... Do we have an nsIContentService to stick a "CanOpenWindow" function for the windowwatcher to call?
Comment 26 Blake Kaplan (:mrbkap) 2010-04-21 18:34:46 PDT
I suppose I could add something to the window watcher service to let it know when the script blocker count goes to or above 0, but that seems like the wrong way for this sort of notification to work.
Comment 27 Blake Kaplan (:mrbkap) 2010-04-23 20:32:31 PDT
Created attachment 441236 [details] [diff] [review]
Better fix
Comment 28 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-23 23:51:22 PDT
Comment on attachment 441236 [details] [diff] [review]
Better fix

Why the fake refcount implementation? Why not create a real service?
Comment 29 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-26 17:33:59 PDT
Comment on attachment 441236 [details] [diff] [review]
Better fix

Minusing per above comment. Please re-request if you disagree.
Comment 30 Blake Kaplan (:mrbkap) 2010-04-27 15:54:58 PDT
Created attachment 441967 [details] [diff] [review]
Better better fix
Comment 31 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-27 16:59:50 PDT
Comment on attachment 441967 [details] [diff] [review]
Better better fix

You could also use NS_GENERIC_FACTORY_CONSTRUCTOR instead of NS_GetContentUtils.

r=me either way.
Comment 32 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-27 17:00:11 PDT
that should say "sr=me either way"
Comment 33 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-04-27 17:02:00 PDT
Though I think we should also land attachment 440668 [details] [diff] [review]
Comment 35 Daniel Veditz [:dveditz] 2010-08-04 15:58:33 PDT
Is there a reason not to land this fix on the stable branches?
Comment 36 Jonas Sicking (:sicking) No longer reading bugmail consistently 2010-08-04 17:19:45 PDT
No, we should take this on branches too IMHO.
Comment 37 Daniel Veditz [:dveditz] 2010-08-06 10:14:53 PDT
Please create a combined branch patch unless these two patches apply as-is (in which case request approval). Thanks!
Comment 38 christian 2010-08-12 23:45:05 PDT
Comment on attachment 441967 [details] [diff] [review]
Better better fix

a=LegNeato for 1.9.2.9.
This needs to be landed as soon as possible.
Comment 39 Blake Kaplan (:mrbkap) 2010-08-13 13:30:03 PDT
http://hg.mozilla.org/releases/mozilla-1.9.2/rev/56ad2e0034a3
Comment 40 christian 2010-08-16 12:51:03 PDT
Comment on attachment 441967 [details] [diff] [review]
Better better fix

a=LegNeato for 1.9.1.12
Comment 41 Blake Kaplan (:mrbkap) 2010-08-16 13:56:10 PDT
http://hg.mozilla.org/releases/mozilla-1.9.1/rev/0c05d8269853
Comment 42 Al Billings [:abillings] 2010-08-23 18:16:26 PDT
(In reply to comment #3)
> Created attachment 416085 [details]
> Test-case
> 
> I've created a reduced test-case.  There is a programming error in the
> website's JavaScript; it reuses a variable for iteration within nested loops. 
> (Somehow, this works on IE ...?)  This bug manifests as a result of DOM
> modification within an infinite loop.
> 
> This can be seen in my test case (where I intentionally duplicate this
> programming error) at lines 19 and 28.
> 
> Be careful with this attachment; it is a very effective DoS.

I note that if I run this testcase in 1.9.2.8, my CPU goes to 99% and stays pegged there. If I run the testcase in the nightly 1.9.2 opt build post-fix, the same thing happens. The same goes for debug builds. 

I saw the same thing with 1.9.1.11 and the nightly opt 1.9.1 build. This is all on Windows XP.

Does the fix not address the DoS issue?
Comment 43 Jason Oster (:Parasyte) 2010-09-21 13:47:09 PDT
I ran the testcase on:

Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.11pre) Gecko/20100919 Ubuntu/10.04 (lucid) Namoroka/3.6.11pre

Firefox became unresponsive for approximately 60 seconds, and then went back to normal, opening the slow-script dialog.  So I was easily able to close the offensive tab after a short wait.  Firefox became unresponsive for approximately 10 seconds after closing the tab, and then went right back to normal.

Same thing happens on further tests.

Dyuring unresponsive times, I also see higher-than-normal CPU activity, but it's hard to judge just how much.  Both of my CPU cores hover around 50% activity during the first wait.  And a single core is pegged at 100% during the second (much shorter) wait.

The DoS is not entirely solved, but user experience is vastly improved over the old behavior.
Comment 44 Al Billings [:abillings] 2010-09-22 15:04:39 PDT
Marking as verified for 1.9.2.

Note You need to log in before you can comment on or make changes to this bug.