Closed Bug 757400 Opened 9 years ago Closed 9 years ago

!!script->compartment()->debugMode() == !!originalDebugMode_

Categories

(Core :: JavaScript Engine, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla15
Tracking Status
firefox15 --- fixed

People

(Reporter: luke, Assigned: jimb)

Details

(Keywords: assertion, Whiteboard: [js:p2])

Attachments

(1 file, 5 obsolete files)

STR:
 1. visit http://syntensity.com/static/bb/client_5.html
 2. wait for it to load up to the main menu
 2. enable the debugger (about:config, devtools.debugger.enabled = true)

Assertion

#0  js::analyze::ScriptAnalysis::assertMatchingDebugMode (this=0x153053b80) at /Volumes/data/moz/mi/js/src/jsanalyze.cpp:2176
#1  js::mjit::Compiler::checkAnalysis js/src/methodjit/Compiler.cpp:182
#2  js::mjit::Compiler::performCompilation js/src/methodjit/Compiler.cpp:535
#3  js::mjit::Compiler::compile js/src/methodjit/Compiler.cpp:146
#4  js::mjit::CanMethodJIT js/src/methodjit/Compiler.cpp:1000
#5  js::RunScript js/src/jsinterp.cpp:291
#6  js::InvokeKernel js/src/jsinterp.cpp:359
#7  js::Invoke jsinterp.h:158
#8  js::Invoke js/src/jsinterp.cpp:391
#9  JS_CallFunctionValue js/src/jsapi.cpp:5503
#10 nsXPCWrappedJSClass::CallMethod js/xpconnect/src/XPCWrappedJSClass.cpp:1509
#11 nsXPCWrappedJS::CallMethod js/xpconnect/src/XPCWrappedJS.cpp:614
#12 PrepareAndDispatch xpcom/reflect/xptcall/src/md/unix/xptcstubs_x86_64_darwin.cpp:153
#13 SharedStub () at xpt_struct.h:334
#14 nsRefreshDriver::Notify layout/base/nsRefreshDriver.cpp:390
#15 nsTimerImpl::Fire xpcom/threads/nsTimerImpl.cpp:511
#16 nsTimerEvent::Run xpcom/threads/nsTimerImpl.cpp:591
#17 nsThread::ProcessNextEvent xpcom/threads/nsThread.cpp:656
#18 NS_ProcessPendingEvents_P
... main event loop

Tested on m-i b5352f7337b1
I hit this as well and put the full log here:

http://past.pastebin.mozilla.org/1647946
Whiteboard: [js:p2]
Ah! I can reproduce this now!
Assignee: general → jimb
I've put together a patch which throws away all analyses in the compartment when transitioning into or out of debug mode (at the moment we only toss them when turning debug mode on), but it didn't address the problem. So I think there's something surprising going on here. The compartment has around 1200 scripts in it, which is making GDB not terribly effective at debugging this. But I'll keep at it Tuesday.
When we turn on debugging in a compartment, JSCompartment::updateForDebugMode attempts to ensure that the compartment gets GC'd, to clear out old jitted code and analyses. However, when running this program, while compartment->isCollecting() is true, compartment->gcPreserveCode is also set, and we fail to throw away the scripts' analyses. Then, JaegerMonkey finds a script in a compartment with debug mode on, with an analysis generated when debug mode was off.
Needs a test case... not quite sure how to go about it, but working on it now.
It's this code that's causing this to fail, occasionally:

    if (c->lastAnimationTime + PRMJ_USEC_PER_SEC >= currentTime &&
        c->lastCodeRelease + (PRMJ_USEC_PER_SEC * 300) >= currentTime) {
        return true;
    }

I used an advanced technique known as "printf debugging" to catch it in the act:

- js::NotifyAnimationActivity sets ((JSCompartment *) 0x7fe234914800)->lastAnimationTime to 1339110949271026
- ((JSCompartment *) 0x7fe234914800)'s debugMode gets set to 0x2, and a GC is requested
- ShouldPreserveJITCode returns true, because currentTime=1339110949294358, within a second of lastAnimationTime
- In SweepPhase, ((JSCompartment *) 0x7fe234914800)->isCollecting() == 1, because AutoDebugModeGC requested it
- In JSCompartment::sweep(this=0x7fe234914800): activeAnalysis=0, gcPreserveCode=1, because ShouldPreserveJITCode requested it
- analyses are not cleared
- assertion fails
One minor detail: failing to throw away the analysis alone wouldn't cause a problem; it's the fact that updateForDebugMode was throwing away the jitted code (via the call to ReleaseScriptCode), *and then* failing to throw away the analysis. Thus the recompilation with the old analysis.
I think I can get this assertion to trigger when leaving debug mode as well. Trying to demonstrate.
This is used by the tests added later in the patch series.
Attachment #631562 - Flags: review?(wmccloskey)
This is used by the tests added later in the patch series.
Attachment #631563 - Flags: review?(wmccloskey)
Always do a cleansing GC when we turn debug mode off, as well as when we
turn it on. If we don't, it's possible to have stale analyses (generated in
the wrong debug mode state) stick around, and we'll assert in JM.

Pass the GC reason all the way from Collect through to
ShouldPreserveJITCode, so that gcreason::DEBUG_MODE_GC can force all jit
code and analyses to be discarded.
Attachment #631564 - Flags: review?(wmccloskey)
Attachment #631110 - Attachment is obsolete: true
Would it be possible to write a test case for this using the existing gcPreserveCode shell function?

Also, rather than checking for the DEBUG_MODE_GC reason specifically, could you change the ShouldCleanUpEverything function in jsgc.cpp to return true if the reason is DEBUG_MODE_GC? Then you won't have to change all those signatures.
(In reply to Bill McCloskey (:billm) from comment #13)
> Would it be possible to write a test case for this using the existing
> gcPreserveCode shell function?

Oh, I hadn't noticed builtin/TestingFunctions.cpp. These functions probably belong there.

It does look like gcPreserveCode will do the trick; I hadn't realize that it was meant for testing.

ShouldCleanUpEverything looked like it would affect other things I didn't want to mess with, but I'll give it a try.
Verified that this fixes the bug in the browser, using the reproduction instructions in comment 0.
Please, no new jsfoo.{h,cpp} files...
Seems like jsutil.h would work fine...
(In reply to :Ms2ger from comment #16)
> Please, no new jsfoo.{h,cpp} files...

They may all go away...
[Revised per billm's comments; no new test functions needed, no PRMJ_Now replacement needed.]

Always do a cleansing GC when we turn debug mode off, as well as when we
turn it on. If we don't, it's possible to have stale analyses (generated in
the wrong debug mode state) stick around, and we'll assert in JM.

Have ShouldCleanUpEverything recognize gcreason::DEBUG_MODE_GC as a reason
to discard all jit code and analyses.
Attachment #631562 - Attachment is obsolete: true
Attachment #631563 - Attachment is obsolete: true
Attachment #631564 - Attachment is obsolete: true
Attachment #631562 - Flags: review?(wmccloskey)
Attachment #631563 - Flags: review?(wmccloskey)
Attachment #631564 - Flags: review?(wmccloskey)
Attachment #632514 - Flags: review?(wmccloskey)
New try: https://tbpl.mozilla.org/?tree=Try&rev=1e99b0059718
Status: NEW → ASSIGNED
Comment on attachment 632514 [details] [diff] [review]
When we change a compartment's debug mode, ensure we throw away all the outdated analyses.

Review of attachment 632514 [details] [diff] [review]:
-----------------------------------------------------------------

::: js/src/jit-test/tests/debug/clear-old-analyses-02.js
@@ +2,5 @@
> +// When we leave debug mode in a compartment, we must throw away all
> +// analyses in that compartment (debug mode affects the results of
> +// analysis, so they become out of date). This is true even when we would
> +// otherwise be retaining jit code and its related data structures for
> +// animation timing.

If I'm not mistaken, this test is about updating debug mode when debugged code is on the stack. So I think this top-level comment is inappropriate?

::: js/src/jscompartment.cpp
@@ -640,5 @@
>  
> -    if (enabled)
> -        JS_ASSERT(!hasScriptsOnStack());
> -    else if (hasScriptsOnStack())
> -        return;

It sounds like this patch addresses two problems. One is the preserving code thing, and the other is this hasScriptsOnStack() issue. Why was this check here in the first place? It seems unnecessary since we can do OSR, but I just want to make sure I understand everything going on here.

::: js/src/jsgc.cpp
@@ +3756,4 @@
>  static bool
>  ShouldCleanUpEverything(JSRuntime *rt, gcreason::Reason reason)
>  {
> +    return !rt->hasContexts() || reason == gcreason::CC_FORCED || reason == gcreason::DEBUG_MODE_GC;

Please put a comment here that we use the DEBUG_MODE_GC reason to ensure that code is discarded when changing debug mode, so this is needed for correctness.
Attachment #632514 - Flags: review?(wmccloskey) → review+
(In reply to Bill McCloskey (:billm) from comment #21)
> If I'm not mistaken, this test is about updating debug mode when debugged
> code is on the stack. So I think this top-level comment is inappropriate?

Yep, stale comment. Thanks.

> It sounds like this patch addresses two problems. One is the preserving code
> thing, and the other is this hasScriptsOnStack() issue. Why was this check
> here in the first place? It seems unnecessary since we can do OSR, but I
> just want to make sure I understand everything going on here.

I think this was an attempt at optimization: since Debugger ignores events that fire in code that's no longer a debuggee, it was believed to be safe to avoid a whole GC pass to clean up debug-mode code. But it's not.

> Please put a comment here that we use the DEBUG_MODE_GC reason to ensure
> that code is discarded when changing debug mode, so this is needed for
> correctness.

I can write a comment for DEBUG_MODE_GC, but I don't understand the other two cases. Could you tell me what to say there? I'll include it in the commit.
(In reply to Jim Blandy :jimb from comment #22)
> I can write a comment for DEBUG_MODE_GC, but I don't understand the other
> two cases. Could you tell me what to say there? I'll include it in the
> commit.

During shutdown, it's really important that we clean up all the garbage. Otherwise it will get reported as a leak on Tinderbox. These cases detect when we're shutting down. CC_FORCED GCs, in particular, happen right before the cycle collection passes at shutdown.
Is this something we should land in Aurora as well?
(In reply to Rob Campbell [:rc] (:robcee) from comment #24)
> Is this something we should land in Aurora as well?

Yes.
(In reply to Rob Campbell [:rc] (:robcee) from comment #24)
> Is this something we should land in Aurora as well?

... what's the procedure for that? How do we get that started?
Go to "details" for the patch, set the "approval‑mozilla‑aurora" flag, fill out the little form, wait for approval.
(In reply to Andrew McCreight [:mccr8] from comment #27)
> Go to "details" for the patch, set the "approval‑mozilla‑aurora" flag, fill
> out the little form, wait for approval.

Thanks. That was an idiot question for Bugzilla; next time I'll check the wiki and maybe IRC.
Comment changed. Added check for gcPreserveCode to test, so it won't fail in non-DEBUG builds.
Attachment #632514 - Attachment is obsolete: true
Flags: in-testsuite+
Comment on attachment 633740 [details] [diff] [review]
When we change a compartment's debug mode, ensure we throw away all the outdated analyses. r=billm

[Approval Request Comment]

Bug caused by (feature/regressing bug #): JS Debugger (long-standing bug)

User impact if declined: Developers using the script debugger can crash Firefox.

Testing completed (on m-c, etc.): Pushed to try.

Risk to taking this patch (and alternatives if risky): Could introduce new debugger bugs. Only affects code paths taken when debugging, so very low risk for non-developers.

String or UUID changes made by this patch: None.
Attachment #633740 - Flags: approval-mozilla-aurora?
Comment on attachment 633740 [details] [diff] [review]
When we change a compartment's debug mode, ensure we throw away all the outdated analyses. r=billm

[Triage Comment]
To prevent crashes in a new feature, with little risk to our everyday user. Approved for Aurora 15.
Attachment #633740 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Inbound: https://hg.mozilla.org/integration/mozilla-inbound/rev/1a2e88e23316

Will let that stew a bit, and then commit to Aurora.
Target Milestone: --- → mozilla15
Target Milestone: mozilla15 → mozilla16
https://hg.mozilla.org/mozilla-central/rev/1a2e88e23316
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Pushed to Aurora:
https://tbpl.mozilla.org/?tree=Mozilla-Aurora&rev=cc068ba06631
Target Milestone: mozilla16 → mozilla15
You need to log in before you can comment on or make changes to this bug.