458838 - TM: Fall off the trace when nested function accesses var of outer function

Status: VERIFIED FIXED

(Core :: JavaScript Engine, defect, P2)

Description

[Boris Zbarsky [:bzbarsky]]

Attachment: Testcase

Testcase attached.  It triggers:

abort: 3028: fp->scopeChain is not global or active call object

Comment 1

[Brendan Eich [:brendan]]

The patch for bug 452498 will totally fix this, so dup'ing. Good testcase, though (bc: I set in-testsuite? -- hope that's ok).

/be

Comment 2

[Bob Clary [:bc] (inactive)]

bz, I tried to add

function testBug458838() {
    var a = 1;
    function g() {
        var b = 0
            for (var i = 0; i < 10; ++i) {
                b += a;
            }
        return b;
    }

    return g();
}
testBug458838.expected = 10;
test(testBug458838);

to js/src/trace-test.js but it passed so I assume trace-test.js is insufficient.

running your original test in 1.9.1 gives for the properties of tracemonkey:

tracemonkey[recorderStarted]=1
tracemonkey[recorderAborted]=1
tracemonkey[traceCompleted]=0
tracemonkey[sideExitIntoInterpreter]=0
tracemonkey[timeoutIntoInterpreter]=0
tracemonkey[typeMapMismatchAtEntry]=0
tracemonkey[returnToDifferentLoopHeader]=0
tracemonkey[traceTriggered]=0
tracemonkey[globalShapeMismatchAtEntry]=3
tracemonkey[treesTrashed]=0
tracemonkey[slotPromoted]=0
tracemonkey[unstableLoopVariable]=0
tracemonkey[breakLoopExits]=0
tracemonkey[returnLoopExits]=0
tracemonkey[mergedLoopExits]=0
tracemonkey[noCompatInnerTrees]=0

should the test simply check that recorderAborted == 0 and traceCompleted == 1 ?

Comment 3

[Boris Zbarsky [:bzbarsky]]

Yeah, exactly.  The test should check that we trace the loop and don't abort.

Comment 4

[Bob Clary [:bc] (inactive)]

Attachment: tests

Comment 5

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 359044 [details] [diff] [review]
tests

r=me with the trace-test also testing the jitstats.

Comment 6

[Bob Clary [:bc] (inactive)]

http://hg.mozilla.org/mozilla-central/rev/b0a380a939bc
/cvsroot/mozilla/js/tests/js1_8_1/trace/regress-458838.js,v  <--  regress-458838.js
initial revision: 1.1

/cvsroot/mozilla/js/tests/js1_8_1/trace/trace-test.js,v  <--  trace-test.js
new revision: 1.10; previous revision: 1.9

Comment 7

[Robert Sayre]

bob, the addition to trace-tests.js is out of sync on the branch. I was able to get

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

to apply in the js/src directory, but not in js/tests.

Comment 8

[Bob Clary [:bc] (inactive)]

rsayre: it looks like mozilla-central and tracemonkey are in sync but mozilla-1.9.1 is missing several patches. I have only been checking into cvs and mozilla-central. Would you like a patch to sync mozilla-1.9.1 with the other repos? Want me to do it?

Comment 9

[Robert Sayre]

(In reply to comment #8)
>
> Would you like a patch to sync mozilla-1.9.1 with the
> other repos? Want me to do it?

A patch for the js/tests directory would be good. (I know some of js/src isn't on 191 yet).

Comment 10

[Bob Clary [:bc] (inactive)]

Attachment: bzip patch sync mozilla-1.9.1 js/tests to mozilla-central js/tests

rsayre: this is a bzip'd patch from mozilla-1.9.1 to mozilla-central for js/tests. I think it will be easier though lacking in history to just apply this. I have another for testing/sisyphus which is much smaller. If this isn't ok to go into mozilla-1.9.1 as is, I can do the hg import magic but it will take me a little while. let me know. fwiw, mozilla-central and tracemonkey are in sync for these two directories.

Comment 11

[Bob Clary [:bc] (inactive)]

Attachment: bzip patch sync mozilla-1.9.1 testing/sisyphus to mozilla-central testing/sisyphus

Comment 12

[Boris Zbarsky [:bzbarsky]]

Reopening.  Bug 452498 did NOT fix this, which we would have trivially detected if we added the test _after_ that landing.  As it was, we landed the test first, it of course failed, and Andreas switched it to expect bailing off trace.  Then bug 452498 landed... and this testcase still bails off trace, so the testcase which expects it to bail kept passing.

When I run the test attached to this bug against a current debug shell on t-m with TRACEMONKEY="abort", I get an abort like so:

  abort: 7895: upvar out of reach
  Abort recording of tree /Users/bzbarsky/test.js:5@13 at
    /Users/bzbarsky/test.js:6@17: getupvar.

Nominating, if this is actually supposed to work.  If not, then why not?

Comment 13

[Brendan Eich [:brendan]]

Sorry about this. We should not hide bugs by making tests expect trace-aborts, which means known failure tracking or tolerance.

/be

Comment 14

[Brendan Eich [:brendan]]

Dave, this is the bug we discussed the other week (month?) -- did you hack on a patch? Feel free to steal.

/be

Comment 15

[Brendan Eich [:brendan]]

(In reply to comment #12)
>   abort: 7895: upvar out of reach

Mystery achievement
Where's my sandy beach?
Yeah, I had my dreams like everybody else
But they're out of reach
I said right out of reach

- C. Hynde, 1980(?)

Lyrical inspiration for dmandelin...

/be

Comment 16

[David Mandelin [:dmandelin]]

Attachment: Patch

This patch correctly executes getupvar operations on the test case in trace-tests, a couple more test cases I made, and the one from bug 460050 (with a 3x speedup on the latter). 

Otherwise, it passes trace-tests and I'll go ahead and run the regression suite tomorrow. But is there another source of testcases? Have we recorded the tests from the previous upvar patches, or I am supposed to request fuzzer coverage or something?

Comment 17

[Brendan Eich [:brendan]]

Great work! (Hope the Pretenders song helped ;-).)

The many fuzz tests in the upvar2 bug have been incorporated into the js tests; look at js/tests/js1_8_1/regress/regress-452498-*.js.

/be

Comment 18

[Boris Zbarsky [:bzbarsky]]

> (with a 3x speedup on the latter). 

Awesome!  I assume that puts us squarely on the "faster than no jit" side of the fence there?

Comment 19

[Andreas Gal :gal]

We need some error handling here in case we run out of memory on trace. You can't use NativeToValue here since its designed specifically to be called from the frame writeback and uses a reserve area.

Comment 20

[David Mandelin [:dmandelin]]

It seems tragic to have to check for OOM when the allocation is not truly necessary. The reason it is 'needed' now:

In the case (1) where the upvar resides in a currently existing interpreter frame, the native js_GetUpvarOnTrace calls js_GetUpvar, which returns an unboxed value. Then the trace unboxes the value.

In the other case (2), the upvar resides in the trace native stack. So that I can use the same trace for both cases, I get the upvar from the trace native stack, then box it. The trace unboxes the value just as in the first case.

It would be much nicer if instead, in case (2), I could just get the upvar and return it directly. Presumably this could work with a little conditional logic before (testing skip > callDepth) or after (testing the return value somehow) the call to js_GetUpvarOnTrace. I think this would also require adding a type check guard on the value returned from the upvar. (It is implicit in the unboxing, so if we skip the unboxing, we could add it.)

Is there any reasonable way of doing this? Do LIR forward jumps work for this? Or imacros?

Comment 21

[David Mandelin [:dmandelin]]

Attachment: Patch v2

This addresses the OOM-on-box problem the previous patch had. Perf is the same (takes the go benchmark from a 1.5x slowdown to a 1.9x speedup.) Summary of the new implementation strategy:

The main idea is to have the builtin that does most of the work (js_GetUpvarOnTrace) return a native value (double). This way, when the value was native to begin with, there is no need for boxing or allocation. For this to be safe, we need to exit the trace if the type of the upvar's value does not match the type it had during recording.

To make this work, js_GetUpvarOnTrace needs 2 output values: the native value, which is returned via pointer, and the typemap type of that value, which is the return value. The trace can then allocate space for the native value, call the function, guard on the result type, and finally load the value out of the allocated space. Much thanks to Andreas for figuring all this out and helping me with my 7000 implementation questions.

Comment 22

[Brendan Eich [:brendan]]

Comment on attachment 375892 [details] [diff] [review]
Patch v2

>+    for (uintN i = 0; i < frameIndex; ++i) {
>+        nativeStackFramePos += state->callstackBase[i]->s.spdist;
>+    }

Drive-by nit: don't overbrace single-line bodies with single-line heads.

>+    FrameInfo* fi = state->callstackBase[frameIndex];
>+    uint8* typemap = (uint8*) (fi+1);
>+
>+    uintN slot = UPVAR_FRAME_SLOT(cookie);
>+    if (slot != CALLEE_UPVAR_SLOT)
>+        slot += 2;

If slot is CALLEE_UPVAR_SLOT don't you need to set slot = 0?

>+        LIns* call = lir->insCall(ci, args);

Tradition wants call_ins as the LIns* variable's name ;-).

/be

Comment 23

[Brendan Eich [:brendan]]

Need to adjust the regression test to expect, nay, *demand* a speedup, in the patch?

/be

Comment 24

[Boris Zbarsky [:bzbarsky]]

We don't have a way to test perf in our regression tests here, last I checked...

Comment 25

[Brendan Eich [:brendan]]

bz: we have jitstats at least. Maybe that's enough.

/be

Comment 26

[Boris Zbarsky [:bzbarsky]]

Oh, sure.  This patch should be fixing the jitstats on the test that was already checked in for this bug (to trace and not abort).

Comment 27

[Andreas Gal :gal]

Comment on attachment 375892 [details] [diff] [review]
Patch v2

>diff -r 6534f8b9aa74 js/src/builtins.tbl
>--- a/js/src/builtins.tbl	Sun May 03 20:43:55 2009 -0400
>+++ b/js/src/builtins.tbl	Tue May 05 15:33:37 2009 -0700
>@@ -84,8 +84,9 @@ BUILTIN3(extern, BOOL,      js_HasNamedP
> BUILTIN3(extern, BOOL,      js_HasNamedPropertyInt32, CONTEXT, OBJECT, INT32,   0, 0)
> BUILTIN3(extern, JSVAL,     js_CallGetter, CONTEXT, OBJECT, SCOPEPROP,          0, 0)
> BUILTIN2(extern, STRING,    js_TypeOfObject, CONTEXT, OBJECT,                   1, 1)
> BUILTIN2(extern, STRING,    js_TypeOfBoolean, CONTEXT, INT32,                   1, 1)
> BUILTIN2(extern, DOUBLE,    js_BooleanOrUndefinedToNumber, CONTEXT, INT32,      1, 1)
> BUILTIN2(extern, STRING,    js_BooleanOrUndefinedToString, CONTEXT, INT32,      1, 1)
> BUILTIN1(extern, OBJECT,    js_Arguments, CONTEXT,                              0, 0)
> BUILTIN4(extern, OBJECT,    js_NewNullClosure, CONTEXT, OBJECT, OBJECT, OBJECT, 0, 0)
>+BUILTIN4(extern, UINT32,    js_GetUpvarOnTrace, CONTEXT, UINT32, UINT32, DOUBLEPTR, 0, 0)
>diff -r 6534f8b9aa74 js/src/jsbuiltins.h
>--- a/js/src/jsbuiltins.h	Sun May 03 20:43:55 2009 -0400
>+++ b/js/src/jsbuiltins.h	Tue May 05 15:33:37 2009 -0700
>@@ -205,16 +205,17 @@ struct JSTraceableNative {
> #define _JS_CTYPE_OBJECT_FAIL       _JS_CTYPE(JSObject *,             _JS_PTR, --, --, FAIL_STATUS)
> #define _JS_CTYPE_CONSTRUCTOR_RETRY _JS_CTYPE(JSObject *,             _JS_PTR, --, --, FAIL_NULL | \
>                                                                                   JSTN_CONSTRUCTOR)
> #define _JS_CTYPE_REGEXP            _JS_CTYPE(JSObject *,             _JS_PTR, "","r", INFALLIBLE)
> #define _JS_CTYPE_SCOPEPROP         _JS_CTYPE(JSScopeProperty *,      _JS_PTR, --, --, INFALLIBLE)
> #define _JS_CTYPE_SIDEEXIT          _JS_CTYPE(SideExit *,             _JS_PTR, --, --, INFALLIBLE)
> #define _JS_CTYPE_INTERPSTATE       _JS_CTYPE(InterpState *,          _JS_PTR, --, --, INFALLIBLE)
> #define _JS_CTYPE_FRAGMENT          _JS_CTYPE(nanojit::Fragment *,    _JS_PTR, --, --, INFALLIBLE)
>+#define _JS_CTYPE_DOUBLEPTR         _JS_CTYPE(double *,               _JS_PTR, --, --, INFALLIBLE)
> 
> #define _JS_EXPAND(tokens)  tokens
> 
> #define _JS_CTYPE_TYPE2(t,s,p,a,f)      t
> #define _JS_CTYPE_TYPE(tyname)          _JS_EXPAND(_JS_CTYPE_TYPE2    _JS_CTYPE_##tyname)
> #define _JS_CTYPE_RETSIZE2(t,s,p,a,f)   s##_RETSIZE
> #define _JS_CTYPE_RETSIZE(tyname)       _JS_EXPAND(_JS_CTYPE_RETSIZE2 _JS_CTYPE_##tyname)
> #define _JS_CTYPE_ARGSIZE2(t,s,p,a,f)   s##_ARGSIZE
>diff -r 6534f8b9aa74 js/src/jstracer.cpp
>--- a/js/src/jstracer.cpp	Sun May 03 20:43:55 2009 -0400
>+++ b/js/src/jstracer.cpp	Tue May 05 15:33:37 2009 -0700
>@@ -1755,16 +1755,59 @@ FlushNativeGlobalFrame(JSContext* cx, un
>         debug_only_v(printf("%s%u=", vpname, vpnum);)
>         NativeToValue(cx, *vp, *mp, np + gslots[n]);
>         ++mp;
>     );
>     debug_only_v(printf("\n");)
>     return mp - mp_base;
> }
> 
>+/*
>+ * Builtin to get an upvar on trace. See js_GetUpvarOnTrace for the meaning
>+ * of the first three arguments. The value of the upvar is stored in *result
>+ * as an unboxed native. The return value is the typemap type.
>+ */
>+int32 JS_FASTCALL
>+js_GetUpvarOnTrace(JSContext *cx, uintN level, uintN cookie, double* result)
>+{
>+    uintN skip = UPVAR_FRAME_SKIP(cookie);
>+    InterpState* state = cx->interpState;
>+    uintN callDepth = state->rp - state->callstackBase;

If you use unsigned math, I suggest some asserts to guard that rp > callstackBase.

>+
>+    /*
>+     * If we are skipping past all frames that are part of active traces,
>+     * then we simply get the value from the interpreter state.
>+     */
>+    if (skip > callDepth) {
>+        jsval v = js_GetUpvar(cx, level, cookie);
>+        uint8 type = getCoercedType(v);
>+        ValueToNative(cx, v, type, result);
>+        return type;
>+    }
>+
>+    /*
>+     * The value we need is logically in a stack frame that is part of
>+     * an active trace. We reconstruct the value we need from the tracer
>+     * stack records.
>+     */
>+    uintN frameIndex = callDepth - skip; // pos of target frame in rp stack

Here too.

>+    uintN nativeStackFramePos = 0; // pos of target stack frame in sp stack
>+    for (uintN i = 0; i < frameIndex; ++i) {
>+        nativeStackFramePos += state->callstackBase[i]->s.spdist;
>+    }

Uber-nit: No need for {}.

>+    FrameInfo* fi = state->callstackBase[frameIndex];
>+    uint8* typemap = (uint8*) (fi+1);
>+
>+    uintN slot = UPVAR_FRAME_SLOT(cookie);
>+    if (slot != CALLEE_UPVAR_SLOT)
>+        slot += 2;

This needs a comment. Maybe += (1/*this*/ + 1/*callee*/). 

>+    *result = state->stackBase[nativeStackFramePos + slot];
>+    return typemap[slot];
>+}
>+
> /**
>  * Box the given native stack frame into the virtual machine stack. This
>  * is infallible.
>  *
>  * @param callDepth the distance between the entry frame into our trace and
>  *                  cx->fp when we make this call.  If this is not called as a
>  *                  result of a nested exit, callDepth is 0.
>  * @param mp pointer to an array of type tags (JSVAL_INT, etc.) that indicate
>@@ -7886,19 +7929,71 @@ TraceRecorder::record_JSOP_GETUPVAR()
> {
>     uintN index = GET_UINT16(cx->fp->regs->pc);
>     JSScript *script = cx->fp->script;
> 
>     JSUpvarArray* uva = JS_SCRIPT_UPVARS(script);
>     JS_ASSERT(index < uva->length);
> 
>     uintN skip = UPVAR_FRAME_SKIP(uva->vector[index]);
>-    if (skip > callDepth)
>-        ABORT_TRACE("upvar out of reach");
>-
>+    if (skip > callDepth) {
>+        /*
>+         * The frame containing the upvar is not part of the trace, so we 
>+         * get the upvar value exactly as the interpreter does and unbox.
>+         */
>+        jsval v = js_GetUpvar(cx, script->staticLevel, uva->vector[index]);
>+        uint8 type = getCoercedType(v);
>+
>+        LIns* outp = lir->insAlloc(sizeof(double));
>+
>+        LIns* args[] = { 
>+            outp,
>+            lir->insImm(uva->vector[index]), 
>+            lir->insImm(script->staticLevel), 
>+            cx_ins 
>+        };
>+        const CallInfo* ci = &js_GetUpvarOnTrace_ci;
>+        LIns* call = lir->insCall(ci, args);
>+        guard(true,
>+              addName(lir->ins2(LIR_eq, call, lir->insImm(type)),
>+                      "guard(type-stable upvar)"),
>+              BRANCH_EXIT);
>+
>+        LOpcode loadOp;
>+        switch (type) {
>+        case JSVAL_DOUBLE:
>+            loadOp = LIR_ldq;
>+            break;
>+        case JSVAL_OBJECT:
>+        case JSVAL_STRING:
>+        case JSVAL_TFUN:
>+            loadOp = LIR_ldp;
>+            break;
>+        case JSVAL_INT:
>+        case JSVAL_TNULL:
>+        case JSVAL_BOOLEAN:
>+            loadOp = LIR_ld;
>+            break;
>+        case JSVAL_BOXED:
>+        default:
>+            JS_NOT_REACHED("found boxed type in an upvar type map entry");
>+            return JSRS_STOP;
>+        }
>+
>+        LIns* result = lir->insLoad(loadOp, outp, lir->insImm(0));
>+        if (type == JSVAL_INT)
>+            result = lir->ins1(LIR_i2f, result);
>+        stack(0, result);
>+        return JSRS_CONTINUE;
>+    }
>+
>+    /*
>+     * At this point, the frame containing the upvar is part of the trace,
>+     * so the upvar is in the tracker. We only need to update the tracker.
>+     */
>     JSStackFrame* fp2 = cx->display[script->staticLevel - skip];
>     JS_ASSERT(fp2->script);
> 
>     uintN slot = UPVAR_FRAME_SLOT(uva->vector[index]);
>     jsval* vp;
>     if (!fp2->fun) {
>         vp = fp2->slots + fp2->script->nfixed;
>     } else if (slot < fp2->fun->nargs) {
>diff -r 6534f8b9aa74 js/src/jstracer.h
>--- a/js/src/jstracer.h	Sun May 03 20:43:55 2009 -0400
>+++ b/js/src/jstracer.h	Tue May 05 15:33:37 2009 -0700
>@@ -344,17 +344,17 @@ public:
> typedef enum JSBuiltinStatus {
>     JSBUILTIN_BAILED = 1,
>     JSBUILTIN_ERROR = 2
> } JSBuiltinStatus;
> 
> struct InterpState
> {
>     double        *sp;                  // native stack pointer, stack[0] is spbase[0]
>-    void          *rp;                  // call stack pointer
>+    FrameInfo**   rp;                   // call stack pointer
>     JSContext     *cx;                  // current VM context handle
>     double        *eos;                 // first unusable word after the native stack
>     void          *eor;                 // first unusable word after the call stack
>     VMSideExit*    lastTreeExitGuard;   // guard we exited on during a tree call
>     VMSideExit*    lastTreeCallGuard;   // guard we want to grow from if the tree
>                                         // call exit guard mismatched
>     void*          rpAtLastTreeCall;    // value of rp at innermost tree call guard
>     TreeInfo*      outermostTree;       // the outermost tree we initially invoked

Comment 28

[Brendan Eich [:brendan]]

(In reply to comment #27)
Overcite!

> >+    uintN callDepth = state->rp - state->callstackBase;
> 
> If you use unsigned math, I suggest some asserts to guard that rp >
> callstackBase.

Isn't this jstracer.cpp's job elsewhere, where it pushes and pops rp?

If truly necessary and not vacuous or misplaced here, >= not > of course.

> >+    if (skip > callDepth) {
> >+        jsval v = js_GetUpvar(cx, level, cookie);
> >+        uint8 type = getCoercedType(v);
> >+        ValueToNative(cx, v, type, result);
> >+        return type;
> >+    }
> >+
> >+    /*
> >+     * The value we need is logically in a stack frame that is part of
> >+     * an active trace. We reconstruct the value we need from the tracer
> >+     * stack records.
> >+     */
> >+    uintN frameIndex = callDepth - skip; // pos of target frame in rp stack
> 
> Here too.

No, because if (skip > callDepth) the code above (good slight overcite here!) returns early. So here, inspection of local code proves that skip <= callDepth.

Java's brain-damaged lack of unsigned types has tainted you! :-P

> >+    uintN slot = UPVAR_FRAME_SLOT(cookie);
> >+    if (slot != CALLEE_UPVAR_SLOT)
> >+        slot += 2;
> 
> This needs a comment. Maybe += (1/*this*/ + 1/*callee*/). 

That's backward -- maybe a prefixed comment with a slot number line labeled by well-known slot names would be better.

Back to vacation for me, just took a lunch break! :-).

/be

Comment 29

[Andreas Gal :gal]

Too many asserts is barely enough. Die often and early, and preferably near to where it happens.

Comment 30

[Brendan Eich [:brendan]]

We have lots of asserts, I've always used 'em -- but no vacuous asserts. 12 lines in a single function, including blank lines and comments, separate a condition that forks control flow into an exit block from the place where the inverse of that condition can and should be assumed.

/be

Comment 31

[David Mandelin [:dmandelin]]

Pushed to TM as 9ae3933eade9.

Comment 32

[Boris Zbarsky [:bzbarsky]]

I can confirm that this bug is now fixed on t-m.  However, the trace-test was not changed, so now it's failing (confirming that the bug is fixed).

Comment 33

[Robert Sayre]

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

Comment 34

[Robert Sayre]

http://hg.mozilla.org/releases/mozilla-1.9.1/rev/0d20e013d76e

Comment 35

[Bob Clary [:bc] (inactive)]

v 1.9.1, 1.9.2

Comment 36

[Bob Clary [:bc] (inactive)]

cvsroot/mozilla/js/tests/js1_8_1/trace/trace-test.js,v  <--  trace-test.js
new revision: 1.14; previous revision: 1.13

/cvsroot/mozilla/js/tests/shell.js,v  <--  shell.js