Intermittent browser_dbg_variables-view-reexpand-02.js | application crashed [@ mozilla::dom::AutoJSAPI::InitInternal(nsIGlobalObject *,JSObject *,JSContext *,bool)]

RESOLVED WORKSFORME

Status

()

Core
DOM
--
critical
RESOLVED WORKSFORME
6 months ago
5 months ago

People

(Reporter: Treeherder Bug Filer, Assigned: mccr8)

Tracking

({crash, intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(crash signature)

(Reporter)

Description

6 months ago
treeherder
Filed by: cbook [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=96625053&repo=mozilla-central

https://queue.taskcluster.net/v1/task/J77_vsKuSpOpIM4lCH0VHg/runs/0/artifacts/public/logs/live_backing.log
Assertion failure: false (We had an exception; we should not have), at z:/build/build/src/dom/base/ScriptSettings.cpp:439
16:08:32     INFO -  GECKO(2716) | #01: mozilla::dom::AutoJSAPI::Init(nsIGlobalObject *,JSContext *) [dom/base/ScriptSettings.cpp:483]
16:08:32     INFO -  GECKO(2716) | #02: mozilla::dom::AutoJSAPI::Init(nsIGlobalObject *) [dom/base/ScriptSettings.cpp:489]
16:08:32     INFO -  GECKO(2716) | #03: nsXBLBinding::ChangeDocument(nsIDocument *,nsIDocument *) [dom/xbl/nsXBLBinding.cpp:750]
16:08:32     INFO -  GECKO(2716) | #04: nsBindingManager::RemovedFromDocumentInternal(nsIContent *,nsIDocument *,nsBindingManager::DestructorHandling) [dom/xbl/nsBindingManager.cpp:215]
16:08:32     INFO -  GECKO(2716) | #05: mozilla::dom::RemoveFromBindingManagerRunnable::Run() [dom/base/Element.cpp:1751]
16:08:32     INFO -  GECKO(2716) | #06: nsContentUtils::AddScriptRunner(already_AddRefed<nsIRunnable>) [dom/base/nsContentUtils.cpp:5479]
16:08:32     INFO -  GECKO(2716) | #07: nsContentUtils::AddScriptRunner(nsIRunnable *) [dom/base/nsContentUtils.cpp:5489]
16:08:32     INFO -  GECKO(2716) | #08: mozilla::dom::Element::UnbindFromTree(bool,bool) [dom/base/Element.cpp:1852]
16:08:32     INFO -  GECKO(2716) | #09: nsXULElement::UnbindFromTree(bool,bool) [dom/xul/nsXULElement.cpp:893]
16:08:32     INFO -  GECKO(2716) | #10: AnonymousContentDestroyer::Run() [dom/base/nsContentUtils.cpp:5176]
16:08:32     INFO -  GECKO(2716) | #11: nsContentUtils::RemoveScriptBlocker() [dom/base/nsContentUtils.cpp:5413]
16:08:32     INFO -  GECKO(2716) | #12: nsDocumentViewer::DestroyPresShell() [layout/base/nsDocumentViewer.cpp:4644]
16:08:32     INFO -  GECKO(2716) | #13: nsDocumentViewer::Destroy() [layout/base/nsDocumentViewer.cpp:1739]
16:08:32     INFO -  GECKO(2716) | #14: nsSHEntryShared::RemoveFromBFCacheSync() [docshell/shistory/nsSHEntryShared.cpp:249]
16:08:32     INFO -  GECKO(2716) | #15: nsSHEntryShared::~nsSHEntryShared() [docshell/shistory/nsSHEntryShared.cpp:107]
16:08:32     INFO -  GECKO(2716) | #16: nsSHEntryShared::Release() [docshell/shistory/nsSHEntryShared.cpp:109]
16:08:32     INFO -  GECKO(2716) | #17: nsCOMPtr_base::~nsCOMPtr_base() [obj-firefox/dist/include/nsCOMPtr.h:294]
16:08:32     INFO -  GECKO(2716) | #18: mozilla::dom::DeferredFinalizerImpl<nsISupports>::DeferredFinalize(unsigned int,void *) [obj-firefox/dist/include/mozilla/dom/BindingUtils.h:2803]
16:08:32     INFO -  GECKO(2716) | #19: mozilla::IncrementalFinalizeRunnable::ReleaseNow(bool) [xpcom/base/CycleCollectedJSRuntime.cpp:1300]
16:08:32     INFO -  GECKO(2716) | #20: mozilla::CycleCollectedJSRuntime::FinalizeDeferredThings(mozilla::CycleCollectedJSContext::DeferredFinalizeType) [xpcom/base/CycleCollectedJSRuntime.cpp:1372]
16:08:32     INFO -  GECKO(2716) | #21: mozilla::CycleCollectedJSRuntime::OnGC(JSGCStatus) [xpcom/base/CycleCollectedJSRuntime.cpp:1415]
16:08:32     INFO -  GECKO(2716) | #22: mozilla::CycleCollectedJSRuntime::GCCallback(JSContext *,JSGCStatus,void *) [xpcom/base/CycleCollectedJSRuntime.cpp:821]
16:08:32     INFO -  GECKO(2716) | #23: js::gc::GCRuntime::callGCCallback(JSGCStatus) [js/src/jsgc.cpp:1457]
16:08:32     INFO -  GECKO(2716) | #24: js::gc::GCRuntime::gcCycle(bool,js::SliceBudget &,JS::gcreason::Reason) [js/src/jsgc.cpp:6529]
16:08:32     INFO -  GECKO(2716) | #25: js::gc::GCRuntime::collect(bool,js::SliceBudget,JS::gcreason::Reason) [js/src/jsgc.cpp:6660]
16:08:32     INFO -  GECKO(2716) | #26: js::gc::GCRuntime::gcSlice(JS::gcreason::Reason,__int64) [js/src/jsgc.cpp:6746]
16:08:32     INFO -  GECKO(2716) | #27: js::gc::GCRuntime::gcIfRequested() [js/src/jsgc.cpp:6939]
16:08:32     INFO -  GECKO(2716) | #28: InternalCall [js/src/vm/Interpreter.cpp:515]
16:08:32     INFO -  GECKO(2716) | #29: js::Call(JSContext *,JS::Handle<JS::Value>,JS::Handle<JS::Value>,js::AnyInvokeArgs const &,JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:534]
16:08:32     INFO -  GECKO(2716) | #30: js::Wrapper::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/Wrapper.cpp:166]
16:08:32     INFO -  GECKO(2716) | #31: js::CrossCompartmentWrapper::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/CrossCompartmentWrapper.cpp:353]
16:08:32     INFO -  GECKO(2716) | #32: js::Proxy::call(JSContext *,JS::Handle<JSObject *>,JS::CallArgs const &) [js/src/proxy/Proxy.cpp:479]
16:08:32     INFO -  GECKO(2716) | #33: js::proxy_Call(JSContext *,unsigned int,JS::Value *) [js/src/proxy/Proxy.cpp:739]
16:08:32     INFO -  GECKO(2716) | #34: js::CallJSNative(JSContext *,bool (*)(JSContext *,unsigned int,JS::Value *),JS::CallArgs const &) [js/src/jscntxtinlines.h:291]
16:08:32     INFO -  GECKO(2716) | #35: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:452]
16:08:32     INFO -  GECKO(2716) | #36: InternalCall [js/src/vm/Interpreter.cpp:515]
16:08:32     INFO -  GECKO(2716) | #37: js::Call(JSContext *,JS::Handle<JS::Value>,JS::Handle<JS::Value>,js::AnyInvokeArgs const &,JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:534]
16:08:32     INFO -  GECKO(2716) | #38: js::jit::InvokeFunction(JSContext *,JS::Handle<JSObject *>,bool,bool,unsigned int,JS::Value *,JS::MutableHandle<JS::Value>) [js/src/jit/VMFunctions.cpp:114]
16:08:32     INFO -  GECKO(2716) | #39: ??? (???:???)
16:08:32     INFO -  GECKO(2716) | #40: ??? (???:???)
16:08:32     INFO -  GECKO(2716) | #41: ??? (???:???)
16:08:32     INFO -  GECKO(2716) | #42: ??? (???:???)
16:08:32     INFO -  GECKO(2716) | #43: ??? (???:???)
bz: could you take a look ?
Flags: needinfo?(bzbarsky)
Right, so we're failing the "We had an exception; we should not have" assertion there.

Relevant part of the log:

16:08:32     INFO -  GECKO(2716) | PREEXISTING EXCEPTION OBJECT: 'Error: Permission denied for <http://example.com> to create wrapper for object of class UnnamedClass'
16:08:32     INFO -  GECKO(2716) | http://example.com/browser/devtools/client/debugger/test/mochitest/doc_with-frame.html:22
16:08:32     INFO -  GECKO(2716) | _propertyDescriptor@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:464:14
16:08:32     INFO -  GECKO(2716) | GenericObject@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:1454:16
16:08:32     INFO -  GECKO(2716) | Object@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:1869:12
16:08:32     INFO -  GECKO(2716) | grip@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:135:15
16:08:32     INFO -  GECKO(2716) | objectGrip@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:1691:14
16:08:32     INFO -  GECKO(2716) | pauseObjectGrip@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:1726:12
16:08:32     INFO -  GECKO(2716) | createValueGrip@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:2194:14
16:08:32     INFO -  GECKO(2716) | createValueGrip@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:1700:29
16:08:32     INFO -  GECKO(2716) | _propertyDescriptor@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:488:22
16:08:32     INFO -  GECKO(2716) | onPrototypeAndProperties@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/object.js:269:29
16:08:32     INFO -  GECKO(2716) | onPacket@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/main.js:1759:15
16:08:32     INFO -  GECKO(2716) | receiveMessage@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/transport/transport.js:761:7
16:08:32     INFO -  GECKO(2716) | enter@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:350:5
16:08:32     INFO -  GECKO(2716) | _pushThreadPause@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:533:5
16:08:32     INFO -  GECKO(2716) | _pauseAndRespond@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:741:7
16:08:32     INFO -  GECKO(2716) | pauseAndRespond@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:870:16
16:08:32     INFO -  GECKO(2716) | _makeOnStep/<@resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/server/actors/script.js:851:16
16:08:32     INFO -  GECKO(2716) | test@http://example.com/browser/devtools/client/debugger/test/mochitest/doc_with-frame.html:22:13
16:08:32     INFO -  GECKO(2716) | onclick@http://example.com/browser/devtools/client/debugger/test/mochitest/doc_with-frame.html:1:1
16:08:32     INFO -  GECKO(2716) | synthesizeMouseAtPoint@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:395:7
16:08:32     INFO -  GECKO(2716) | synthesizeMouse@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:326:10
16:08:32     INFO -  GECKO(2716) | synthesizeMouseAtCenter@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:459:10
16:08:32     INFO -  GECKO(2716) | this.generateMouseClick@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/code_frame-script.js:40:3
16:08:32     INFO -  GECKO(2716) | @chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/code_frame-script.js:78:12
16:08:32     INFO -  GECKO(2716) | promise callback*@chrome://mochitests/content/browser/devtools/client/debugger/test/mochitest/code_frame-script.js:77:3

That first file/line is just the "debugger" statement that presumably triggers the rest of the test.

What's particularly awesome is that the line the stack implicates (devtools/server/actors/object.js line 464) is in a try/catch.  So how could it lead to an exception that sticks around on the JSContext?

Well, that presumably happens because js::InternalCallOrConstruct has this bit:

    /* Perform GC if necessary on exit from the function. */
    AutoGCIfRequested gcIfRequested(cx->runtime());

and this is what leads to the callstack above.  That is, we call CycleCollectedJSRuntime::GCCallback while an exception is pending on the JSContext and we're in the middle of returning false from InternalCallOrConstruct.  We end up doing a CycleCollectedJSRuntime::OnGC(JSGC_END), which does deferred finalization, which tries to use JSAPI, and here we are.

So which assumption is bogus here?  Is it the assumption that arbitrary JSAPI usage is OK under JSGC_END notification?  Or the assumption that you can do GC with a pending exception?  Or something else?
Flags: needinfo?(bzbarsky) → needinfo?(sphink)
Bleh, this is ugly.

I'm not crazy about saying that any of those is wrong. mccr8, what if we saved and restored the exception state around JSGC_END notification? Is there a place to report any exception triggered by JSGC_END itself? Some sort of noisy way to drop it on the floor.
Flags: needinfo?(sphink) → needinfo?(continuation)
(Assignee)

Comment 5

5 months ago
Hmm. It seems questionable to me to do immediate finalization when there is JS on the stack, but I guess we do need to do that at least for testing. Why do we GC right there? Seems pretty sketchy. We could just always defer finalization if there's a pending exception, maybe...
(Assignee)

Updated

5 months ago
Depends on: 1364528
(Assignee)

Comment 6

5 months ago
This problem doesn't seem to have happened more than once, but it still makes me concerned. I filed bug 1364528 about my suggested fix for this issue.
Flags: needinfo?(continuation)
(Assignee)

Updated

5 months ago
Assignee: nobody → continuation
Status: NEW → RESOLVED
Last Resolved: 5 months ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.