Last Comment Bug 679977 - TM: Variable assignment fails, gets assigned undefined
: TM: Variable assignment fails, gets assigned undefined
Status: RESOLVED FIXED
:
Product: Core
Classification: Components
Component: JavaScript Engine (show other bugs)
: Trunk
: All All
: -- normal (vote)
: mozilla9
Assigned To: Shu-yu Guo [:shu]
:
: Jason Orendorff [:jorendorff]
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2011-08-17 19:55 PDT by Jon Buckley
Modified: 2011-08-31 19:33 PDT (History)
12 users (show)
emorley: in‑testsuite+
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Testcase (3.48 KB, application/x-javascript)
2011-08-26 06:53 PDT, Jan de Mooij [:jandem]
no flags Details
More minimal testcase. (1.46 KB, application/javascript)
2011-08-28 11:39 PDT, Terrence Cole [:terrence]
no flags Details
Even more minimal testcase (497 bytes, application/javascript)
2011-08-29 21:20 PDT, Shu-yu Guo [:shu]
no flags Details
Fix (2.70 KB, patch)
2011-08-29 21:21 PDT, Shu-yu Guo [:shu]
gal: review+
Details | Diff | Splinter Review
Properly formatted patch and testcase (3.59 KB, patch)
2011-08-30 14:15 PDT, Shu-yu Guo [:shu]
no flags Details | Diff | Splinter Review

Description Jon Buckley 2011-08-17 19:55:44 PDT
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:6.0) Gecko/20100101 Firefox/6.0
Build ID: 20110811165603

Steps to reproduce:

In the process of developing Processing.js v1.3, we started running into a strange error in our reference test suite where the variable assignment would fail, and get assigned undefined instead.

I've managed to reduce this problem a little, and have a github branch up at https://github.com/jbuck/processing-js/tree/firefox-bug/ . You can also visit http://jbuckley.ca/~jon/processing-js/test/ref/ if you just want to run it.

To run the test suite, click the "Remove Passed Tests" checkbox, and hit the "Start" button.

This bug is present in Firefox 6 and Firefox Nightly Debug on Mac OS X 10.6 and Windows 7. It also doesn't appear in any of the other major browsers (Chrome, IE9, Safari 5.1, Opera) on either platform.


Actual results:

The test suite will stop executing on test 33 with an error "cachedVertArray is undefined @ http://jbuckley.ca/~jon/processing-js/processing.js:12145"

The interesting part of the code is in the previous for loop:
for (i = 0; i < vertArrayLength; i++) {
  cachedVertArray = vertArray[i]; /* This gets assigned undefined sometimes */
  if (!cachedVertArray) {
    console.log("vertices failed");
    cachedVertArray = vertArray[i]; /* But if we assign it again, it works fine! */




Expected results:

It should've continued drawing the color wheel, rather than dying.

I spoke to several people on #jsapi about this bug:
sstangl: jbuck: it's a JIT bug in JaegerMonkey. If you turn off 'javascript.options.methodjit.content' in about:config, it passes.
sfink: you could also try a debug build to see if you can get an assert out of it

I confirmed that turning off mjit makes the test suite complete properly. The debug build did not give me any useful assertions, just messages related to "WARNING: Unsupported filter type!: file /builds/slave/m-cen-osx64-dbg/build/gfx/layers/opengl/LayerManagerOGL.cpp, line 1172" 

Let me know if I can provide any more information, I'll continue trying to reduce this testcase.
Comment 1 David Humphrey (:humph) 2011-08-17 19:59:36 PDT
Confirmed, I'm bisecting now to try and find a regression window.
Comment 2 David Humphrey (:humph) 2011-08-17 20:34:13 PDT
I can't lock it down, but I've been able to reproduce it back as far as 2010-10-31 (http://hg.mozilla.org/mozilla-central/rev/18caa24f974d) on m-c, so it's not a new regression.
Comment 3 David Humphrey (:humph) 2011-08-22 12:01:53 PDT
One thing about the code that's failing, and which may or may not be related...the array that's being lost by the JIT is being used like this:

var arr = [];
...
arr['some-string'] = true;
...
arr[0] = someNumber;
arr[1] = someOtherNumber;
...

We know this is wrong, and should be an object vs. an array, but I thought I'd mention it in case it's relevant.
Comment 4 Boris Zbarsky [:bz] (still a bit busy) 2011-08-25 13:41:01 PDT
This looks bad...
Comment 5 Jan de Mooij [:jandem] 2011-08-26 01:35:29 PDT
Looks like a tracer integration bug. I'll try to reduce this.
Comment 6 Jan de Mooij [:jandem] 2011-08-26 06:53:21 PDT
Created attachment 556017 [details]
Testcase

After converting this to a shell testcase it was fairly easy to automatically reduce. The attached file fails with -j on the TI branch. The initial testcase also failed on mozilla-central with -m -j, but after reducing it only fails on the TI branch. Probably due to some small differences in GC or trace aborts.

$ ./js -j test.js
test.js:28: Error: Assertion failed: got 719, expected 720

===
25 var vertArrayLength = vertArray.length;
26 assertEq(vertArray.length, 720);
27 for (var i = 0; i < vertArrayLength; i++) {
28     assertEq(vertArray.length, 720);
29     var cachedVertArray = vertArray[i];
30     assertEq(cachedVertArray !== undefined, true);
31 }
===
Somehow the array length is invalid inside the loop. Output with TMFLAGS=minimal:
===
Recording starting from test.js:79@19 (FragID=000000)
  [0.879 ms] Tree at line 44 executed for 0 iterations; executed 8 times; leave for LOOP at test.js:43 (lt)
  [0.711 ms] Tree at line 28 executed for 0 iterations; executed 7 times; leave for LOOP at test.js:27 (lt)
Recording completed at  test.js:79@19 via closeLoop (FragID=000000)

  [1.544 ms] Tree at line 79 executed for 0 iterations; executed 1 times; leave for NESTED at test.js:28 (call)
test.js:28: Error: Assertion failed: got 719, expected 720
===
Comment 7 Jan de Mooij [:jandem] 2011-08-26 06:59:41 PDT
Throwing back. I've never hacked the tracer before and I don't have much time atm.
Comment 8 Boris Zbarsky [:bz] (still a bit busy) 2011-08-26 09:19:24 PDT
My first instinct is that something is stomping on memory somewhere here, which if true is really bad.  dmandelin, can we find someone to look at this?
Comment 9 Terrence Cole [:terrence] 2011-08-28 11:39:23 PDT
Created attachment 556416 [details]
More minimal testcase.

Inlining the first draw appears to remove the failure without changing the order of calls to arc, so I think this is about as minimal as it is likely to get.
Comment 10 Shu-yu Guo [:shu] 2011-08-29 17:23:03 PDT
The loop that's traced in |endShape| never gets re-traced. When it first gets traced, the trace bakes in the Call object from |(new Processing(Processing.compile(0))).draw();|.

When we trace the outer loop in |compile| in |new Processing(Processing.compile(1));|, we link to the existing |endShape| trace that we have. But that trace has the wrong Call object baked in!

We should be bailing on a guard somewhere that isn't happening. Will investigate further.
Comment 11 Shu-yu Guo [:shu] 2011-08-29 21:18:57 PDT
(In reply to Shu-yu Guo [:shu] from comment #10)
> The loop that's traced in |endShape| never gets re-traced. When it first
> gets traced, the trace bakes in the Call object from |(new
> Processing(Processing.compile(0))).draw();|.
> 
> When we trace the outer loop in |compile| in |new
> Processing(Processing.compile(1));|, we link to the existing |endShape|
> trace that we have. But that trace has the wrong Call object baked in!
> 
> We should be bailing on a guard somewhere that isn't happening. Will
> investigate further.

What I said wasn't entirely correct. This is a really subtle bug!

What's actually going on is that the first call to |draw| causes us to record a trace of |arc| where its parent is a deactivated stack frame. This causes the upvar lookup of |vertArray| to be baked in without us guarding on the callee's parent. The tracer, I guess, assumes that we never get a deactivated stack frame without |guardCallee| also being called, which this bug shows to be false. So when we construct the second Processing object, we end up stitching in the recorded |draw| trace even though the closure for |arc| is now a completely different object. So when we execute that trace we've been pushing into the |vertArray| in the first closure, not the second.
Comment 12 Shu-yu Guo [:shu] 2011-08-29 21:20:45 PDT
Created attachment 556746 [details]
Even more minimal testcase

It's important that we keep the |assertEq(true, true)| line, as importing it between the first and second Processing creation perturbs the global object shape, causing re-recording, which in fact fixes the bug.
Comment 13 Shu-yu Guo [:shu] 2011-08-29 21:21:43 PDT
Created attachment 556747 [details] [diff] [review]
Fix

When I tested this bug is present in m-c and m-i also, not just JM.
Comment 14 Andreas Gal :gal 2011-08-29 21:29:57 PDT
Comment on attachment 556747 [details] [diff] [review]
Fix

Nice fix.
Comment 15 David Mandelin [:dmandelin] 2011-08-30 07:33:02 PDT
Comment on attachment 556747 [details] [diff] [review]
Fix

Only one review is needed. Shu, thanks much for fixing this!
Comment 16 Ed Morley [:emorley] 2011-08-30 12:43:31 PDT
Shu, thanks for the patch :-) It's in my queue with a few other bits that are being sent to try first and then onto inbound.

To save time for future patches, could you set your hgrc to include the author automatically & also add a commit message, along the lines of:
http://blog.bonardo.net/2010/06/22/so-youre-about-to-use-checkin-needed

Thanks :-)
Comment 17 Shu-yu Guo [:shu] 2011-08-30 14:10:25 PDT
Hi Ed,

Sorry for the bad formatting. I'll attach a properly formatted patch.
Comment 18 Shu-yu Guo [:shu] 2011-08-30 14:15:07 PDT
Created attachment 556990 [details] [diff] [review]
Properly formatted patch and testcase
Comment 20 Marco Bonardo [::mak] 2011-08-31 02:09:02 PDT
http://hg.mozilla.org/mozilla-central/rev/72974e2ef258
Comment 21 Brendan Eich [:brendan] 2011-08-31 19:04:51 PDT
Shu has progressed to level of tracing-JIT badass!

/be
Comment 22 Jon Buckley 2011-08-31 19:33:27 PDT
Just tested my firefox-bug branch with the Aug 31st Nightly, and it worked properly!

Thanks for the quick turn-around on this bug shu

Note You need to log in before you can comment on or make changes to this bug.