474771 - TM: JS execution halts in this testcase with gczeal, prototype mangling, for..in

Status: VERIFIED FIXED

(Core :: JavaScript Engine, defect, P1)

Description

[Jesse Ruderman]

gczeal(2);
Object.prototype.q = 3;
for each (let x in [6, 7]) { } print("PASS");

With -j, "PASS" never gets printed, but there are no assertion failures.

TRACEMONKEY=verbose says:
Abort recording (line 3, pc 35): error or exception while recording.

Initially security-sensitive because the testcase involves gczeal.

Comment 1

[Andreas Gal :gal]

We never run trace code, we abort tracing. Graydon recently mucked with this. I don't remember the bug # and I am too tired to look it up, but ccing him.

whale:src gal$ ./Darwin_DBG.OBJ/js -j x.js
recorder: started(1), aborted(1), completed(0), different header(0), trees trashed(0), slot promoted(0), unstable loop variable(0), breaks(0), returns(0), unstableInnerCalls(0)
monitor: triggered(0), exits(0), type mismatch(0), global mismatch(1)
whale:src gal$ TRACEMONKEY=verbose ./Darwin_DBG.OBJ/js -j x.js
Global shape mismatch (2 vs. 4294967295), flushing cache.
Flushing cache.
capture stack type stack0: 1=I
capture stack type stack1: 0=O
capture stack type stack2: 1=I
recording starting from x.js:3@37
globalObj=0x285000, shape=2
import vp=0x814018 name=$stack0 type=int flags=0
import vp=0x81401c name=$stack1 type=object flags=0
import vp=0x814020 name=$stack2 type=int flags=0
    start
    state = param 0 ecx
    0
    sp = ld state[0]
    4
    rp = ld state[4]
    12
    cx = ld state[12]
    8
    gp = ld state[8]
    16
    eos = ld state[16]
    20
    eor = ld state[20]
    ld1 = ld sp[0]
    $stack0 = i2f ld1
    $stack1 = ld sp[8]
    ld2 = ld sp[16]
    $stack2 = i2f ld2
    ld3 = ld cx[0]
    4096
    sub1 = sub ld3, 4096
    sti cx[0] = sub1
    le1 = le sub1, 0
    xt1: xt le1 -> 0:37 sp+24 rp+0

00037:   3  forlocal 0
00040:   3  nextiter
    sti sp[0] = ld2
    ld4 = ld $stack1[4]
    -4
    and1 = and ld4, -4
    clasp
    guard(class is Iterator) = eq and1, clasp
    xf1: xf guard(class is Iterator) -> 0:40 sp+24 rp+0

    js_FastCallIteratorNext1 = js_FastCallIteratorNext ( cx $stack1 )
    eq1 = eq js_FastCallIteratorNext1, JSVAL_ERROR_COOKIE
    xt2: xt eq1 -> 0:40 sp+24 rp+0

Abort recording (line 3, pc 40): error or exception while recording.
recorder: started(1), aborted(1), completed(0), different header(0), trees trashed(0), slot promoted(0), unstable loop variable(0), breaks(0), returns(0), unstableInnerCalls(0)
monitor: triggered(0), exits(0), type mismatch(0), global mismatch(1)

Comment 2

[Brendan Eich [:brendan]]

Not clear yet why the patch for bug 470310 regressed this. That bug's patch called js_AbortRecording but did not change interpreter state AFAICT at a glance. I'll have a quick look.

/be

Comment 3

[Brendan Eich [:brendan]]

js_AddAsGCBytes sees gczeal and acts as if under memory pressure, but then it tests JS_ON_TRACE(cx) and returns false -- silent failure. Correct when actually executing a trace (JS_EXECUTING_TRACE(cx)), possibly not when recording. We used to not tolerate GC during recording, but we may now.

So this bug has always been there -- it's not a regression from bug 470310. I'm gonna put it back in the pool, hoping sayrer can find a good assignee. Need to get to the end of the upvar tunnel (there's light, it's not a train ;-).

/be

Comment 4

[Mike Shaver (:shaver emeritus)]

My reading of that analysis is that this is not a security-sensitive bug (because the gczeal issue is not related to more eager collection) and that it needn't block 3.1.  Is that an incorrect reading?

Comment 5

[Brendan Eich [:brendan]]

Yes on this bug not being s-s. Not sure about 3.1 yet.

/be

Comment 6

[Andreas Gal :gal]

Really not my favorite kind of bug but this needs an owner.

Comment 7

[Andreas Gal :gal]

Attachment: patch

This patch no longer sets onTrace during recording, so the GC is allowed to run. This will eventually invalide the trace since tm->globalShape is set to -1 by the GC, which makes it not match whatever the new (re-numbered) shape of the global object is.

The code refers to setting onTrace for "rooting" reasons. I can't think of a reason to set this any more. The only jsval* we keep is a copy of global_dslots, which we use to abort if dslots get reallocated. GC is likely to do that, but if we come up with a different dslots after the GC we would abort here.

Jesse, could you fuzz this patch with GCZeal on?

Comment 8

[Andreas Gal :gal]

Jesse: we are mostly interested in recording here, so bang at the recorder. We don't think the actual code execution matters all that much. Its mostly recording with gczeal enabled or gczeal being set at unpleasant moments. For this it should be set within the loop in different places.

Comment 9

[Brendan Eich [:brendan]]

See bug 462042. I don't think we want to violate invariants that depend on recording setting JS_ON_TRACE(cx). Why not test JS_EXECUTING_TRACE(cx) instead of JS_ON_TRACE(cx)? But we'll still need jorendorff's patch. It seems this bug is a dup of bug 462042.

/be

Comment 10

[Andreas Gal :gal]

What invariants are those?

Comment 11

[Jesse Ruderman]

This patch makes this testcase assert, even though there doesn't seem to be any gc involved:

var o = {};
o.__defineSetter__('x', function(){});
for (let j = 0; j < 4; ++j) o.x = 3;

Assertion failure: jumpTable == interruptJumpTable, at ../jsinterp.cpp:2775

Comment 12

[Brendan Eich [:brendan]]

(In reply to comment #10)
> What invariants are those?

Hello, comment 11 :-P.

See jorendorff's comments in the patch for bug 462042. Recording models tracing not just (or necessarily, when bug 462042 is fixed) in suppressing GC attempts. Most of the JS_ON_TRACE(cx) test are assertions about invariants modeled when recording, which must hold when executing, traces. A few are non-assertion tests in unifdef'ed code. Here's the grep output:

jsapi.cpp:    return JS_ON_TRACE(cx) || cx->fp != NULL;
jsapi.cpp:    JS_ASSERT(!JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));                                               \
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsdate.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsgc.cpp:            && !JS_ON_TRACE(cx) && !JS_TRACE_MONITOR(cx).useReservedObjects
jsgc.cpp:                if (doGC || JS_ON_TRACE(cx))
jsgc.cpp:    if (!JS_ON_TRACE(cx))
jsgc.cpp:                    if (didGC || JS_ON_TRACE(cx)) {
jsgc.cpp:                        if (!JS_ON_TRACE(cx))
jsgc.cpp:        if (JS_ON_TRACE(cx)) {
jsgc.cpp:    JS_ASSERT_IF(gckind == GC_LAST_DITCH, !JS_ON_TRACE(cx));
jsgc.cpp:    if (JS_ON_TRACE(cx))
jsinterp.cpp:    if (JS_ON_TRACE(cx)) {
jsobj.cpp:    JS_ASSERT_IF(entryp, !JS_ON_TRACE(cx));
jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));

/be

Comment 13

[Andreas Gal :gal]

The invariants seem to cover builtins and paths called from builtins, but we do not call builtins while recording. We take the regular recording path. Why would be have invariants beyond that? The recorder path is identical to the non-recording regular execution path, or at least it should be (minus imacros).

Comment 14

[Andreas Gal :gal]

These asserts are definitively builtin/from-trace only:

jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsstr.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsobj.cpp:    JS_ASSERT_IF(entryp, !JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsarray.cpp:    JS_ASSERT(JS_ON_TRACE(cx));                                    
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsbuiltins.cpp:    JS_ASSERT(JS_ON_TRACE(cx));
jsdate.cpp:    JS_ASSERT(JS_ON_TRACE(cx));

jsgc and jsinterp need a little investigating. I think whatever assert uses "JS_ON_TRACE" to decided whether we record is dead wrong and should be fixed.

Comment 15

[Andreas Gal :gal]

Attachment: v2

New version. Please more fuzzing, Jesse :)

Comment 16

[Brendan Eich [:brendan]]

Recording follows the interpreter (including imacros) to generate code. It was at least once upon a time crucial to preserve certain relations from recording time to trace execution time. Maybe we don't need that sense of JS_ON_TRACE(cx) any longer. Jason should weigh in.

/be

Comment 17

[Jason Orendorff [:jorendorff]]

Bug 462042 fixes a problem that hasn't been introduced yet:  the sequence (deep bail; GC; start recording; return to trace) would crash.  The patch there fixes the bug by prohibiting recording between the deep bail and the return to trace.

This patch will conflict a bit with my patch in that bug, but don't let that stop you.

I'm all for changing the meaning of JS_ON_TRACE(cx) as suggested.  Comment 14 seems too optimistic in its pessimism.  I don't think existing uses of JS_ON_TRACE(cx) are all broken in the same way; there's no telling what the existing uses mean--but, don't let that stop you either.

Comment 18

[Andreas Gal :gal]

Attachment: v3

Comment 19

[Andreas Gal :gal]

Attachment: v4, rebased since we just backed out a patch that overlapped

Comment 20

[Jesse Ruderman]

With v4, bug 469234 goes away, but jsfunfuzz hits this frequently:

this.__defineSetter__('x', function(){})
for (var j = 0; j < 5; ++j) { x = 3; }

Comment 21

[Andreas Gal :gal]

Attachment: v5, don't set onTrace when re-entering the interpreter during recording

Comment 23

[Andreas Gal :gal]

Attachment: v5 with additional test cases that this patch also fixes

Comment 24

[Andreas Gal :gal]

Comment on attachment 358538 [details] [diff] [review]
v5 with additional test cases that this patch also fixes

Already casually reviewed by danderson.

Comment 25

[Brendan Eich [:brendan]]

Comment on attachment 358538 [details] [diff] [review]
v5 with additional test cases that this patch also fixes


> #ifdef JS_TRACER
>     /* We had better not be entering the interpreter from JIT-compiled code. */
>+    TraceRecorder *tr = TRACE_RECORDER(cx);
>+    SET_TRACE_RECORDER(cx, NULL);

Nit: blank line (one) before major comment.

No need to do this if (!tr), so move the SET_TRACE_RECORDER(cx, NULL); down into the following if's then block:

>+    /* If a recorder is pending and we try to re-enter the interpreter, flag 
>+       the recorder to be destroyed when we return. */
>+    if (tr) {
>+        if (tr->wasDeepAborted())
>+            tr->removeFragmentoReferences();
>+        else
>+            tr->pushAbortStack();
>     }
> #endif

[in jsstaticcheck.h:]

>-#define JS_ASSERT_NOT_EXECUTING_TRACE(cx)   JS_ASSERT(!JS_EXECUTING_TRACE(cx))
>+#define JS_ASSERT_NOT_EXECUTING_TRACE(cx)   JS_ASSERT(!JS_ON_TRACE(cx))

Only two uses, please rename to JS_ASSERT_NOT_ON_TRACE(cx).

Ok, that wasn't so painful! Hope jorendorff likes it too, he's been over this space (in connection with bailing natives) more than I have recently.

r=me with nits above fixed.

/be

Comment 26

[Andreas Gal :gal]

http://hg.mozilla.org/tracemonkey/rev/f5929ecc8b2d
http://hg.mozilla.org/tracemonkey/rev/14dcb06922ba

Comment 27

[Robert Sayre]

this crashes tp on mac

Comment 28

[Andreas Gal :gal]

I was not able to reproduce this using a local talos set.

I was also not able to get the try server to crash.

The only option left is to get a core from one of the production tinderboxes. CC'ing

Comment 29

[Andreas Gal :gal]

Attachment: v6, refreshed to apply cleanly to TraceMonkey tip

Comment 30

[Andreas Gal :gal]

I am re-landing this patch, full well expecting it to blow up badly. I am trying to double check that we really need the talos core dump from build. CCing igor. After one cycle if there is any orange (probably macosx talos crash) please back out the patch.

Comment 31

[Andreas Gal :gal]

Landed on TM to confirm that we still fail:

http://hg.mozilla.org/tracemonkey/rev/39b1c9f21064

Comment 32

[Igor Bukanov]

I backed out the patch - it cause the timeout in the crash test on Mac again, http://tinderbox.mozilla.org/showlog.cgi?log=TraceMonkey/1233057222.1233064224.22437.gz&fulltext=1 . In addition, it regressed on Linux with reftest, http://tinderbox.mozilla.org/showlog.cgi?log=TraceMonkey/1233057222.1233063401.20571.gz&fulltext=1 .

Comment 33

[Mike Shaver (:shaver emeritus)]

Did it crash Talos again, though?

Comment 34

[Igor Bukanov]

(In reply to comment #33)
> Did it crash Talos again, though?

No.

Comment 35

[Andreas Gal :gal]

Landing again, can't reproduce the crash, neither in debug nor in opt builds.

http://hg.mozilla.org/tracemonkey/rev/799a55cfae00

Comment 36

[Robert Sayre]

http://hg.mozilla.org/mozilla-central/rev/799a55cfae00

Comment 37

[Robert Sayre]

http://hg.mozilla.org/releases/mozilla-1.9.1/rev/6d9dcdcbd837

Comment 38

[Bob Clary [:bc] (inactive)]

http://hg.mozilla.org/mozilla-central/rev/e9226dd6c073

Comment 39

[Bob Clary [:bc] (inactive)]

still need to add the test from comment 0.

Comment 40

[Bob Clary [:bc] (inactive)]

http://hg.mozilla.org/tracemonkey/rev/724560fa97ad
/cvsroot/mozilla/js/tests/js1_7/extensions/regress-474771-01.js,v  <--  regress-474771-01.js
initial revision: 1.1
/cvsroot/mozilla/js/tests/js1_7/extensions/regress-474771-02.js,v  <--  regress-474771-02.js
initial revision: 1.1
/cvsroot/mozilla/js/tests/js1_7/regress/regress-474771.js,v  <--  regress-474771.js
initial revision: 1.1

Comment 41

[Bob Clary [:bc] (inactive)]

verified 1.9.1, 1.9.2