569327 - inconsistent for loop performance

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[00003b]

User-Agent:       Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.3a5pre) Gecko/20100531 Minefield/3.7a5pre
Build Identifier: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.3a5pre) Gecko/20100531 Minefield/3.7a5pre

Performance of for loops counting down to 0 using -- drops significantly (5-10x) after entering the loop 3-4 times (either by calling the containing function, or iterating an outer loop), other for loops in first test case get progressively slower for first 30-50 calls, then drops by 3-4x.

Passing the loops to another function in an anonymous function (first test case) is much slower than calling them directly (second test case).


Reproducible: Always

Steps to Reproduce:
1. run tests
2. press 'run test' button
3. repeat step 2, note changes in timings
Actual Results:  
the 4th loop using -- gets 4-10x slower after clicking the button a few times
other loops in first test case get progressively slower (more obvious if the repetition count in the box is increased), then gets another 2-5x slower after 20-50 clicks

second test case is significantly faster than first, but the -- loop still gets slower after a few runs

Expected Results:  
all loops counting same direction (increment vs decrement) have similar times, regardless of how many times they are run

Comment 1

[00003b]

Attachment: test case 1

Comment 2

[00003b]

Attachment: test case 2

Comment 3

[Boris Zbarsky [:bzbarsky]]

> Passing the loops to another function in an anonymous function (first test
> case) is much slower than calling them directly (second test case).

That part makes sense, since not using a closure doesn't have to deal with the complexities of a closure's scope chain, etc.

For the closure case, we branch-exit on each new invocation, then end up hitting MAX_BRANCHES at some point and dropping off the jit; that would explain the ++ and +=1 behavior (get progressively slower, then fall off a cliff).  In particular, we branch-exit on something like:

  leaving trace at /Users/bzbarsky/test.js:31@12, op=nameinc, lr=0x820464,
  exitType=BRANCH, sp=0, calldepth=0, cycles=0

    About to try emitting guard code for SideExit=0x820464 exitType=BRANCH
    $stack0 = ldi.s sp[-40]
    ldi2 = ldi.o $stack0[12]
    map = ldi.o ldi2[0]
    obj_shape = ldi.o map[4]
    immi2 = immi 248
    guard_shape = eqi obj_shape, immi2/*248*/
    xf2: xf guard_shape -> pc=0x40c248 imacpc=0x0 sp+0 rp+0 (GuardID=002)

Presumably this is the Call object's shape, which is different every time because of the non-flat closures involved?

For the decrement case, though, things are more interesting.  For one thing, the dropoff happens around iteration 4-5, not around 32 as would be expected for MAX_BRANCHES.  For another, the behavior depends on the exact DOM accesses the testcase performs.  Looking into that.

Comment 4

[Boris Zbarsky [:bzbarsky]]

Attachment: Smaller testcase that still shows the decrement problem; needs dump enabled in browser

So this part seems to be key (jstracer line number is for some pretty old revision, sorry, but the code is still there in incHelper):

trace stopped: 8533: can only inc numbers
Abort recording of tree file:///Users/bzbarsky/test.html:16@11 at file:///Users/bzbarsky/test.html:16@16: localdec.

This is, of course, what makes the decrement different from the increment in the testcase; in the increment case we know 'i' is an integer while in the decrement case it starts off as a string.  So we go to trace the loop, hit the abort above, back off, then retry some loop iterations later.  At that point, 'i' is an integer, so we trace it that way and finish up the loop.  The next call, the same thing happens.  After a few calls, we blacklist the loop and never try to jit it again.

Comment 5

[Boris Zbarsky [:bzbarsky]]

Confirming, but I think the "expected results" from comment 0 are not reasonable for a tracing jit, in fact, since loop executions are not independent of each other.

Comment 6

[Boris Zbarsky [:bzbarsky]]

And more precisely, we blacklist on the third time through (due to aborts being greater than the mis-documented BL_ATTEMPTS), and then the 4th time through don't record a trace at all.  Of course we wouldn't need to record a trace there period if it were not for the shape guard thing, right?  Can we address that issue here somehow?

Comment 7

[Boris Zbarsky [:bzbarsky]]

Looks like that shape guard comes from traverseScopeChain, fwiw.

Comment 8

[Boris Zbarsky [:bzbarsky]]

Attachment: js shell testcase

Comment 9

[Brendan Eich [:brendan]]

(In reply to comment #7)
> Looks like that shape guard comes from traverseScopeChain, fwiw.

Fixed in tracemonkey by patch for bug 569391.

/be

Comment 10

[Boris Zbarsky [:bzbarsky]]

Right.  I just checked, and that doesn't help with the decrement tests here (though does help with the increment ones), because we still end up aborting + blacklisting...

Comment 11

[David Anderson [:dvander] - inactive, e-mail if emergency]

This doesn't seem to be a problem anymore (in the interim, JM and trace tuning have landed). Boris, can you confirm?

Comment 12

[Boris Zbarsky [:bzbarsky]]

There are several things going on here, actually:

1)  The testcase I attached no longer shows the problem for me on m-c, but if I
    add just one more runTest call it does.  That's using -j.
2)  On TM we trace inc() on strings, so this bug goes away altogether.  See bug
    605858.
3)  If I run under -j -m -p on either m-c or TM there is no problem; the tuning
    is either using JM throughout or switching over seamlessly from TM to JM.

Between #2 and #3, this is definitely fixed.  ;)