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

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Luke Wagner [:luke]]

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

Comment 1

[Panos Astithas (he/him) [:past] (please ni?)]

I hit this as well and put the full log here:

http://past.pastebin.mozilla.org/1647946

Comment 2

[Jim Blandy :jimb]

Ah! I can reproduce this now!

Comment 3

[Jim Blandy :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.

Comment 4

[Jim Blandy :jimb]

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.

Comment 5

[Jim Blandy :jimb]

Attachment: When we request a GC for a debug mode switch, ensure that we really do toss the code and analysis.

Needs a test case... not quite sure how to go about it, but working on it now.

Comment 6

[Jim Blandy :jimb]

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

Comment 7

[Jim Blandy :jimb]

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.

Comment 8

[Jim Blandy :jimb]

I think I can get this assertion to trigger when leaving debug mode as well. Trying to demonstrate.

Comment 9

[Jim Blandy :jimb]

Attachment: Call the new js::Replayable::Now instead of PRMJ_Now in code where differing values could produce non-deterministic behavior.

This is used by the tests added later in the patch series.

Comment 10

[Jim Blandy :jimb]

Attachment: Make js::NotifyAnimationActivity callable from the shell.

This is used by the tests added later in the patch series.

Comment 11

[Jim Blandy :jimb]

Attachment: When we change a compartment's debug mode, ensure we throw away all the outdated analyses.

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.

Comment 12

[Jim Blandy :jimb]

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

Comment 13

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

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.

Comment 14

[Jim Blandy :jimb]

(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.

Comment 15

[Jim Blandy :jimb]

Verified that this fixes the bug in the browser, using the reproduction instructions in comment 0.

Comment 16

[:Ms2ger (he/him; ⌚ UTC+1/+2)]

Please, no new jsfoo.{h,cpp} files...

Comment 17

[Luke Wagner [:luke]]

Seems like jsutil.h would work fine...

Comment 18

[Jim Blandy :jimb]

(In reply to :Ms2ger from comment #16)
> Please, no new jsfoo.{h,cpp} files...

They may all go away...

Comment 19

[Jim Blandy :jimb]

Attachment: When we change a compartment's debug mode, ensure we throw away all the outdated analyses.

[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.

Comment 20

[Jim Blandy :jimb]

New try: https://tbpl.mozilla.org/?tree=Try&rev=1e99b0059718

Comment 21

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

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.

Comment 22

[Jim Blandy :jimb]

(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.

Comment 23

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

(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.

Comment 24

[Rob Campbell [:rc] (:robcee)]

Is this something we should land in Aurora as well?

Comment 25

[Jim Blandy :jimb]

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

Yes.

Comment 26

[Jim Blandy :jimb]

(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?

Comment 27

[Andrew McCreight [:mccr8]]

Go to "details" for the patch, set the "approval‑mozilla‑aurora" flag, fill out the little form, wait for approval.

Comment 28

[Jim Blandy :jimb]

(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 29

[Jim Blandy :jimb]

Attachment: When we change a compartment's debug mode, ensure we throw away all the outdated analyses. r=billm

Comment changed. Added check for gcPreserveCode to test, so it won't fail in non-DEBUG builds.

Comment 30

[Jim Blandy :jimb]

New try: https://tbpl.mozilla.org/?tree=Try&rev=c08e1c072082

Comment 31

[Jim Blandy :jimb]

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.

Comment 32

[Alex Keybl [:akeybl]]

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.

Comment 33

[Jim Blandy :jimb]

Inbound: https://hg.mozilla.org/integration/mozilla-inbound/rev/1a2e88e23316

Will let that stew a bit, and then commit to Aurora.

Comment 34

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/1a2e88e23316

Comment 35

[Jim Blandy :jimb]

Pushed to Aurora:
https://tbpl.mozilla.org/?tree=Mozilla-Aurora&rev=cc068ba06631