520336 - TM: Crash [@ 0x341f850b] or [@ JS_CallTracer] or "Assertion failure: !JSVAL_IS_NULL((scope)->lastProp->id), at ../jsobj.cpp" or "Assertion failure: thing, at ../jsgc.cpp" with gc

Status: VERIFIED FIXED

(Core :: JavaScript Engine, defect, P1)

Description

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

for (let z = 0; z < 4; ++z) {
    var y = uneval({
        x: {
            a: 1
        }
    })
    gc()
}

crashes js opt shell at a scary memory location and asserts js debug shell at Assertion failure: !JSVAL_IS_NULL((scope)->lastProp->id), at ../jsobj.cpp:5114 on TM tip with -j.

Security-sensitive because of scary location and that this concerns gc.


opt stack:

Exception Type:  EXC_BAD_ACCESS (SIGSEGV)
Exception Codes: KERN_INVALID_ADDRESS at 0x00000000341f850b
Crashed Thread:  0

Thread 0 Crashed:
0   ???                           	0x008107d3 0 + 8456147
1   js-opt-tm-darwin              	0x0006e0cf js_GetPropertyHelper + 959
2   js-opt-tm-darwin              	0x0006e1de js_GetProperty + 46
3   js-opt-tm-darwin              	0x00067b13 __ZL16MarkSharpObjectsP9JSContextP8JSObjectPP9JSIdArray + 387
4   js-opt-tm-darwin              	0x00067bf9 __ZL16MarkSharpObjectsP9JSContextP8JSObjectPP9JSIdArray + 617
5   js-opt-tm-darwin              	0x00067df7 js_EnterSharpObject + 311
6   js-opt-tm-darwin              	0x0006936c __ZL12obj_toSourceP9JSContextjPl + 220
7   js-opt-tm-darwin              	0x0005e876 js_Invoke + 1606
8   js-opt-tm-darwin              	0x0005efeb js_InternalInvoke + 139
9   js-opt-tm-darwin              	0x0006e36d js_TryMethod + 285
10  js-opt-tm-darwin              	0x000c84bc js_ValueToSource + 380
11  js-opt-tm-darwin              	0x000c8518 __ZL10str_unevalP9JSContextjPl + 40
12  ???                           	0x007d2ed4 0 + 8203988
13  js-opt-tm-darwin              	0x000f9ae3 __ZL11ExecuteTreeP9JSContextPN7nanojit8FragmentERjPP10VMSideExit + 947
14  js-opt-tm-darwin              	0x00116c78 js_MonitorLoopEdge(JSContext*, unsigned int&, MonitorReason) + 2088
15  js-opt-tm-darwin              	0x0005c2ba js_Interpret + 57610
16  js-opt-tm-darwin              	0x0005df2a js_Execute + 362
17  js-opt-tm-darwin              	0x0000d54c JS_ExecuteScript + 60
18  js-opt-tm-darwin              	0x000040d8 __ZL7ProcessP9JSContextP8JSObjectPci + 1336
19  js-opt-tm-darwin              	0x00008194 main + 2212
20  js-opt-tm-darwin              	0x0000206b _start + 209
21  js-opt-tm-darwin              	0x00001f99 start + 41

Comment 1

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

autoBisect shows this is probably related to bug 517973:

The first bad revision is:
changeset:   32856:f3ea03af0e28
user:        Luke Wagner
date:        Wed Sep 23 18:21:41 2009 -0700
summary:     Bug 517973 - remove deep abort, fix blacklisting bug

Comment 2

[Robert Sayre]

gary, which changeset are you testing?

Comment 3

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

I think I'm on http://hg.mozilla.org/tracemonkey/rev/102a83c28bd0

Possibly related testcase:

new Function
for (var x = 0; x < 22; ++x) {
    if (x % 2 == 1) {
        ({
            getter: function(){}
        });
        gc()
    }
}


This testcase crashes when passed in as a CLI argument to the js shell. The opt stack is similar:

Exception Type:  EXC_BAD_ACCESS (SIGBUS)
Exception Codes: KERN_PROTECTION_FAILURE at 0x0000000000000ff0
Crashed Thread:  0

Thread 0 Crashed:
0   js-opt-tm-darwin              	0x0004a9a5 JS_CallTracer + 117
1   js-opt-tm-darwin              	0x000bfe9d JSScopeProperty::trace(JSTracer*) + 109
2   js-opt-tm-darwin              	0x000ef974 JSTraceMonitor::mark(JSTracer*) + 180
3   js-opt-tm-darwin              	0x0004b8b6 js_TraceRuntime + 182
4   js-opt-tm-darwin              	0x0004bd7e js_GC + 1022
5   js-opt-tm-darwin              	0x0000f3b8 JS_GC + 72
6   js-opt-tm-darwin              	0x000056d2 __ZL2GCP9JSContextjPl + 50
7   ???                           	0x007d2f7a 0 + 8204154
8   js-opt-tm-darwin              	0x000f9ae3 __ZL11ExecuteTreeP9JSContextPN7nanojit8FragmentERjPP10VMSideExit + 947
9   js-opt-tm-darwin              	0x00116c78 js_MonitorLoopEdge(JSContext*, unsigned int&, MonitorReason) + 2088
10  js-opt-tm-darwin              	0x0005c2ba js_Interpret + 57610
11  js-opt-tm-darwin              	0x0005df2a js_Execute + 362
12  js-opt-tm-darwin              	0x0000d54c JS_ExecuteScript + 60
13  js-opt-tm-darwin              	0x000041e5 __ZL7ProcessP9JSContextP8JSObjectPci + 1605
14  js-opt-tm-darwin              	0x00008194 main + 2212
15  js-opt-tm-darwin              	0x0000206b _start + 209
16  js-opt-tm-darwin              	0x00001f99 start + 41


while it asserts at Assertion failure: thing, at ../jsgc.cpp:2657

Comment 4

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

There seems to be many other related crashes (portions of the stacks look similar, but the testcase and crash locations vary wildly), I don't yet have time for many more but I'll test again when this bug is fixed.

How similar? I seem to see lines of "__ZL1.........." on the stacks, e.g. the one above in lines 8 and 13.

Comment 5

[Luke Wagner [:luke]]

I was hoping this was simply bug 520311, which we found today, but it still crashes even with the fix.

The big thing about this patch is that, before this, the recorder would be aborted during GC.  This patch allows the recorder to continue (only later aborting if shapes were regenerated).

A little gdb-ing confirms that GC happens while recording, recording completes successfully, and the assert happens in the first trace execution.  Perhaps this is a rooting problem with the code to generate native calls (str_uneval)?

valgrind doesn't show any invalid memory reads/writes before the assertion.

Comment 6

[Luke Wagner [:luke]]

(In reply to comment #5)
> The big thing about this patch is that, before this, the recorder would be
> aborted during GC.  This patch allows the recorder to continue (only later
> aborting if shapes were regenerated).

To clarify, "this patch" = bug 517973, which was correctly fingered above.

Comment 7

[Brendan Eich [:brendan]]

Assertion failure: !JSVAL_IS_NULL((scope)->lastProp->id), at ../jsobj.cpp:5114

is from an assertion Waldo presciently added just the other day. It means the live scope is pointing to a property tree node that has been swept by the GC. So it does seem that the trace-tree is not rooting enough.

/be

Comment 8

[Brendan Eich [:brendan]]

One way to debug is to get address reproducibility (of lastProp, e.g.) and find where it is being GC'ed. On that stack you should find some tree that has a ref to it still. At least, this is the drill for finding prematurely collected things in many other cases.

/be

Comment 9

[Luke Wagner [:luke]]

I think I found the source of the bug, but I don't know enough about scope properties to fix it; none of my naive attempts worked.

Loop in the crashing test case above contains a new object initialization.  This involves a JSOP_INITPROP which calls record_SetPropHit with the JSScopeProperty* that was just added.  This JSScopeProperty* is baked into the trace in TraeMonitor::setProp as an argument to the js_AddProperty called from trace.  Debugging confirms that this is indeed the JSScopeProperty involved in the failing assertion.

I tried to gcthings.addUnique() the object initialized during recoreding, to keep the JSScopeProperty alive, but that didn't work.  Clearly, I need to read up on GC and the scope chain.

Comment 10

[Brendan Eich [:brendan]]

You almost have it: you want treeInfo->sprops.addUnique(sprop), not ...gcthings...

/be

Comment 11

[Luke Wagner [:luke]]

Attachment: fix

Well, I was too quick to blame it on lack-of-rooting.  Indeed, INS_CONSTSPROP already adds the sprop to treeInfo->ssprops.  The real problem was that JSTraceMonitor:mark() only marks TreeInfo objects for *completed* fragments, which ignores the TreeInfo held by the current recorder.  Simple enough fix.

Comment 12

[Brendan Eich [:brendan]]

Comment on attachment 404467 [details] [diff] [review]
fix

Should've seen this... Thanks!

/be

Comment 13

[Luke Wagner [:luke]]

http://hg.mozilla.org/tracemonkey/rev/20a24e94817f
with trace-test

Comment 14

[Robert Sayre]

the regressing bug didn't land on 1.9.2 yet, so I'm leaving this as ?

Comment 15

[Robert Sayre]

http://hg.mozilla.org/mozilla-central/rev/20a24e94817f

Comment 16

[Bob Clary [:bc] (inactive)]

js/src/trace-test/tests/basic/testGCWhileRecording.js
v 1.9.3

Comment 17

[Luke Wagner [:luke]]

This absolutely must go on 1.9.2, as we now may GC on trace.

Comment 18

[Robert Sayre]

http://hg.mozilla.org/releases/mozilla-1.9.2/rev/c0de224848f0