Last Comment Bug 561031 - Crash [@ js_Interpret] or [@ JSScope::searchTable] or [@ js_LookupPropertyWithFlags] or "Assertion failure: cx->throwing, at ../jsops.cpp" or "Assertion failure: len > 0, at ../jsops.cpp"
: Crash [@ js_Interpret] or [@ JSScope::searchTable] or [@ js_LookupPropertyWit...
Status: VERIFIED FIXED
[sg:critical?][ccbr][fixed-in-tracemo...
: assertion, crash, regression, testcase, verified1.9.1, verified1.9.2
Product: Core
Classification: Components
Component: JavaScript Engine (show other bugs)
: Trunk
: All All
: -- critical (vote)
: ---
Assigned To: Jason Orendorff [:jorendorff]
:
Mentors:
Depends on:
Blocks: jsfunfuzz
  Show dependency treegraph
 
Reported: 2010-04-22 00:39 PDT by Gary Kwong [:gkw] [:nth10sd]
Modified: 2013-01-04 15:57 PST (History)
13 users (show)
choller: in‑testsuite+
See Also:
Crash Signature:
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
beta1+
needed
.4-fixed
needed
.10-fixed


Attachments
1821-line reduced testcase (33.80 KB, text/plain)
2010-04-22 00:39 PDT, Gary Kwong [:gkw] [:nth10sd]
no flags Details
HTML testcase (33.82 KB, text/plain)
2010-04-22 01:16 PDT, Gary Kwong [:gkw] [:nth10sd]
no flags Details
v1 (37.15 KB, patch)
2010-04-22 12:35 PDT, Jason Orendorff [:jorendorff]
brendan: review+
mbeltzner: approval1.9.2.4+
mbeltzner: approval1.9.1.10+
Details | Diff | Review

Description Gary Kwong [:gkw] [:nth10sd] 2010-04-22 00:39:54 PDT
Created attachment 440713 [details]
1821-line reduced testcase

The 1821-line (of which only the last line seems interesting) testcase asserts js debug shell on TM tip without -j at Assertion failure: cx->throwing, at ../jsops.cpp:3581 and crashes js opt shell on TM tip without -j at js_Interpret

During the course of the reduction (many thanks go out to Jesse for his great help!), the asserts varied in message and so did the crash signature location.

I tested on Linux 64-bit, while Jesse was able to reproduce on Mac 32-bit.

s-s because crashing all over the place is scary. Assuming [sg:critical?] unless otherwise.

autoBisect coming up.
Comment 1 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 00:46:24 PDT
js opt stack:

Exception Type:  EXC_BAD_ACCESS (SIGBUS)
Exception Codes: KERN_PROTECTION_FAILURE at 0x000000000000000c
Crashed Thread:  0  Dispatch queue: com.apple.main-thread

Thread 0 Crashed:  Dispatch queue: com.apple.main-thread
0   js-opt-32-tm-darwin           	0x00056bdf js_Interpret + 4479
1   js-opt-32-tm-darwin           	0x00065793 js_Execute + 531
2   js-opt-32-tm-darwin           	0x0000f4dc JS_ExecuteScript + 60
3   js-opt-32-tm-darwin           	0x00004f4f Process(JSContext*, JSObject*, char*, int) + 1647
4   js-opt-32-tm-darwin           	0x00008f8a main + 1626
5   js-opt-32-tm-darwin           	0x00002a7d _start + 208
6   js-opt-32-tm-darwin           	0x000029ac start + 40
Comment 3 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 01:08:44 PDT
I'm unable to bisect this because it goes way back - not as old as the 01 Jan 2006 js shell but it seems to already occur in Jan 2009:

http://hg.mozilla.org/tracemonkey/rev/1dd1af3aec3e

Prior to that I'm unable to compile on my 10.6.x machine.
Comment 4 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 01:16:51 PDT
Created attachment 440717 [details]
HTML testcase

Mac 10.6.3 Firefox 3.5.9 crash report:

bp-3d0af757-5e8c-4270-b561-4709e2100422
Comment 5 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 06:45:50 PDT
(In reply to comment #0)
> During the course of the reduction (many thanks go out to Jesse for his great
> help!), the asserts varied in message and so did the crash signature location.

Examples of possible other crash locations are JSScope::searchTable or js_LookupPropertyWithFlags, while other assert messages are:

Assertion failure: len > 0, at ../jsops.cpp
Assertion failure: StackBase(fp) + OBJ_BLOCK_DEPTH(cx, obj) == regs.sp, at ../jsops.cpp
Comment 6 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 06:56:41 PDT
(In reply to comment #5)
> (In reply to comment #0)
> > During the course of the reduction (many thanks go out to Jesse for his great
> > help!), the asserts varied in message and so did the crash signature location.
> 
> Examples of possible other crash locations are JSScope::searchTable or
> js_LookupPropertyWithFlags, while other assert messages are:
> 
> Assertion failure: len > 0, at ../jsops.cpp
> Assertion failure: StackBase(fp) + OBJ_BLOCK_DEPTH(cx, obj) == regs.sp, at
> ../jsops.cpp

Whoops, left this out:

Assertion failure: (size_t) (regs.sp - StackBase(fp)) >= 2, at ../jsops.cpp
Comment 7 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 07:04:41 PDT
(In reply to comment #6)
> (In reply to comment #5)
> > (In reply to comment #0)
> > > During the course of the reduction (many thanks go out to Jesse for his great
> > > help!), the asserts varied in message and so did the crash signature location.
> > 
> > Examples of possible other crash locations are JSScope::searchTable or
> > js_LookupPropertyWithFlags, while other assert messages are:
> > 
> > Assertion failure: len > 0, at ../jsops.cpp
> > Assertion failure: StackBase(fp) + OBJ_BLOCK_DEPTH(cx, obj) == regs.sp, at
> > ../jsops.cpp
> 
> Whoops, left this out:
> 
> Assertion failure: (size_t) (regs.sp - StackBase(fp)) >= 2, at ../jsops.cpp

Final one before I get bored:

Assertion failure: regs.sp - StackBase(fp) >= 3, at ../jsops.cpp:3429
Comment 8 Jason Orendorff [:jorendorff] 2010-04-22 10:42:03 PDT
The generated code here has the wrong jump offset:

00000:   1  trace
main:
00001:   1  try
00002:   1  goto 7 (5)                        <---- wrong
00005:   1  enterblock depth 0 {e: 0}
00008:   1  exception
00009:   1  setlocalpop 0
00012:   1  leaveblock 1
00015:   1  goto 19 (4)                       <---- right
00018:   1  nop
00019:   2  try

Both should jump to offset 19. The backpatching code works correctly at first. Here is the stack where the correct offset is overwritten:

#0  AddSpanDep (cx=0x827bfa8, cg=0xbfffee18, pc=0x82b4635 "\006", pc2=0x82b4635 "\006", off=17) at ../jsemit.cpp:587
#1  0x08094414 in BuildSpanDepTable (cx=0x827bfa8, cg=0xbfffee18) at ../jsemit.cpp:654
#2  0x08095626 in EmitJump (cx=0x827bfa8, cg=0xbfffee18, op=JSOP_BACKPATCH, off=32768) at ../jsemit.cpp:1187
#3  0x08095c63 in EmitBackPatchOp (cx=0x827bfa8, cg=0xbfffee18, op=JSOP_BACKPATCH, lastp=0xbfffec84) at ../jsemit.cpp:1344
#4  0x08096176 in EmitGoto (cx=0x827bfa8, cg=0xbfffee18, toStmt=0xbfffec78, lastp=0xbfffec84, label=0x0, noteType=SRC_NULL) at ../jsemit.cpp:1479
#5  0x0809dac7 in js_EmitTree (cx=0x827bfa8, cg=0xbfffee18, pn=0x8280e08) at ../jsemit.cpp:4543
#6  0x080fadcd in js::Compiler::compileScript (cx=0x827bfa8, scopeChain=((JSObject *) 0xb7c02000) [object global], callerFrame=0x0, principals=
    0x0, tcflags=24576, chars=((jschar *) NULL), length=0, file=0x8280458, filename=0xbffff579 "silly.js", lineno=1, source=((JSString *) NULL), 
    staticLevel=0) at ../jsparse.cpp:856
#7  0x08068be9 in JS_CompileFileHandleForPrincipals (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", 
    file=0x8280458, principals=0x0) at ../jsapi.cpp:4606
#8  0x08068b3a in JS_CompileFileHandle (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", file=
    0x8280458) at ../jsapi.cpp:4592
#9  0x0804ac64 in Process (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", forceTTY=0)
    at ../../shell/js.cpp:445
#10 0x0804b9b2 in ProcessArgs (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], argv=0xbffff3c8, argc=1) at ../../shell/js.cpp:863
#11 0x080534bf in main (argc=1, argv=0xbffff3c8, envp=0xbffff3d0) at ../../shell/js.cpp:5045
Comment 9 Andreas Gal :gal 2010-04-22 10:50:50 PDT
Could we remove BuildSpanDepTable? dvander measured that it rarely saves anything, but always costs time.
Comment 10 Brendan Eich [:brendan] 2010-04-22 11:16:25 PDT
(In reply to comment #9)
> Could we remove BuildSpanDepTable? dvander measured that it rarely saves
> anything, but always costs time.

This is like saying "could we always emit 32-bit jump offsets?" Maybe but is it going to waste too much space or ding one of our time-perf metrics? That is more work to answer.

How about we fix this old bug directly, instead of asking questions that do not actually do a thing to fix this old bug?

/be
Comment 11 Brendan Eich [:brendan] 2010-04-22 11:19:31 PDT
(In reply to comment #9)
> Could we remove BuildSpanDepTable? dvander measured that it rarely saves
> anything, but always costs time.

"always costs time" is false -- it should not even be called except for large scripts (ones that have <-32K/>=32K jump offsets or >=32K deltas between jumps to backpatch.

dvander, are you seeing it called for small scripts? Stack or it didn't happen :-P

/be
Comment 12 Brendan Eich [:brendan] 2010-04-22 11:28:10 PDT
(In reply to comment #11)
> dvander, are you seeing it called for small scripts? Stack or it didn't happen
> :-P

Of course, it can happen with a jump far down in a big straight line script, since the first backpatch-delta is from top of script. That's what is happening here.

/be
Comment 13 Brendan Eich [:brendan] 2010-04-22 11:30:07 PDT
(In reply to comment #12)
> (In reply to comment #11)
> > dvander, are you seeing it called for small scripts? Stack or it didn't happen
> > :-P
> 
> Of course, it can happen with a jump far down in a big straight line script,
> since the first backpatch-delta is from top of script.

Actually from (top of script AKA 0 offset) - 1, hence the goto being emitted at 32767 having a bpdelta of 32768.

/be
Comment 14 Jason Orendorff [:jorendorff] 2010-04-22 12:15:19 PDT
OK, the actual stack where the offset is overwritten with bad stuff is shown below. BuildSpanDepTable is not the culprit. When we return from BuildSpanDepTable, the JSJumpTarget for that instruction is correct (the offset is 18). Below it is changed to 5 while we are emitting bytecode for an unrelated statement.

#0  SetSpanDepTarget (cx=0x827bfa8, cg=0xbfffee18, sd=0x82ebeb8, off=5) at ../jsemit.cpp:530
#1  0x0809582c in js_SetJumpOffset (cx=0x827bfa8, cg=0xbfffee18, pc=0x8305379 "\256", off=5) at ../jsemit.cpp:1235
#2  0x080a2d6d in js_EmitTree (cx=0x827bfa8, cg=0xbfffee18, pn=0x82e55f8) at ../jsemit.cpp:6279
#3  0x080a0ce9 in js_EmitTree (cx=0x827bfa8, cg=0xbfffee18, pn=0x82e5658) at ../jsemit.cpp:5658
#4  0x080a097c in js_EmitTree (cx=0x827bfa8, cg=0xbfffee18, pn=0x82e51e8) at ../jsemit.cpp:5575
#5  0x0809db6a in js_EmitTree (cx=0x827bfa8, cg=0xbfffee18, pn=0x8280e08) at ../jsemit.cpp:4554
#6  0x080fadcd in js::Compiler::compileScript (cx=0x827bfa8, scopeChain=((JSObject *) 0xb7c02000) [object global], callerFrame=0x0, principals=
    0x0, tcflags=24576, chars=((jschar *) NULL), length=0, file=0x8280458, filename=0xbffff579 "silly.js", lineno=1, source=((JSString *) NULL), 
    staticLevel=0) at ../jsparse.cpp:856
#7  0x08068be9 in JS_CompileFileHandleForPrincipals (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", 
    file=0x8280458, principals=0x0) at ../jsapi.cpp:4606
#8  0x08068b3a in JS_CompileFileHandle (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", file=
    0x8280458) at ../jsapi.cpp:4592
#9  0x0804ac64 in Process (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], filename=0xbffff579 "silly.js", forceTTY=0)
    at ../../shell/js.cpp:445
#10 0x0804b9b2 in ProcessArgs (cx=0x827bfa8, obj=((JSObject *) 0xb7c02000) [object global], argv=0xbffff3c8, argc=1) at ../../shell/js.cpp:863
#11 0x080534bf in main (argc=1, argv=0xbffff3c8, envp=0xbffff3d0) at ../../shell/js.cpp:5045
Comment 15 Jason Orendorff [:jorendorff] 2010-04-22 12:18:43 PDT
That in turn is happening because js_SetJumpOffset calls GetSpanDep(cg, pc) to get the JSSpanDep to update; but:

(gdb) p pc - cg->main.base
$1 = 32773
(gdb) n
1235	    return SetSpanDepTarget(cx, cg, GetSpanDep(cg, pc), off);
(gdb) s
GetSpanDep (cg=0xbfffee18, pc=0x8305379 "\256") at ../jsemit.cpp:674
674	    index = GET_SPANDEP_INDEX(pc);
(gdb) n
675	    if (index != SPANDEP_INDEX_HUGE)
(gdb) p index
$2 = 0
(gdb) x/3bx pc
0x8305379:	0xae	0x00	0x00
(gdb) p (JSOp) 0xae
$3 = JSOP_FILTER

This instruction hasn't been assigned a JSSpanDep yet. So GetSpanDep will carelessly return cg->spanDeps[0], the record for the very first jump in the script.
Comment 16 Jason Orendorff [:jorendorff] 2010-04-22 12:35:50 PDT
Created attachment 440847 [details] [diff] [review]
v1

One-line patch, 1831-line test.

I don't really understand this code well enough to say whether this is the right fix. It does fix the particular case at hand.

js> disfile("tests/e4x/Regress/regress-561031.js")
00000:  trace
main:
00001:  try
00002:  goto 19 (17)
00005:  enterblock depth 0 {e: 0}
00008:  exception
00009:  setlocalpop 0
00012:  leaveblock 1
00015:  goto 19 (4)
00018:  nop
00019:  try
...

This bug seems exploitable to me.
Comment 17 Brendan Eich [:brendan] 2010-04-22 12:46:51 PDT
Comment on attachment 440847 [details] [diff] [review]
v1

Thanks -- whew! This goes back to the dawn of E4X.

$ egrep 'JSOP_(OR|AND|GOSUB|CASE|DEFAULT|IF)' jsemit.cpp|grep Emit3

comes up empty for me, and JSOP_ENDFILTER is emitted via EmitJump. It looks like JSOP_FILTER is the only jump emitted incorrectly (not via EmitJump), pre-patch.

/be
Comment 18 Jason Orendorff [:jorendorff] 2010-04-22 18:54:54 PDT
http://hg.mozilla.org/tracemonkey/rev/2323d5dfeaa1
Comment 19 Gary Kwong [:gkw] [:nth10sd] 2010-04-22 21:07:43 PDT
This testcase was found via the compareJIT part of jsfunfuzz.
Comment 20 Mike Beltzner [:beltzner, not reading bugmail] 2010-04-23 13:20:56 PDT
This is needed for now, but as soon as you land and bake it on mozilla-central please renominate as we'll want to get it out in the immediately following security and stability release.
Comment 22 Mike Beltzner [:beltzner, not reading bugmail] 2010-04-26 10:12:40 PDT
a=beltzner, please land on mozilla-1.9.1 default, mozilla 1.9.2 default AND
mozilla-1.9.2 GECKO1924_20100413_RELBRANCH
Comment 23 christian 2010-04-26 15:32:51 PDT
Friendly notice: both the 1.9.1.10 and 1.9.2.4 code freezes are scheduled for *tomorrow*, Tuesday April 27th 2010 @ 11:59 pm PST.
Comment 25 Benjamin Smedberg [:bsmedberg] 2010-04-28 12:20:24 PDT
Setting equivalent flags.
Comment 26 Al Billings [:abillings] 2010-04-30 15:59:09 PDT
Gary, can you verify that this is fixed on 1.9.2 and 1.9.1 nightlies?
Comment 27 Gary Kwong [:gkw] [:nth10sd] 2010-05-01 09:04:56 PDT
32-192-34148-410e8b21dfeb/js-opt-32-192-darwin 1reducedmore.js 
1reducedmore.js:1821: TypeError: XML filter is applied to non-XML value []

32-191-26906-e28579a43585/js-opt-32-191-darwin 1reducedmore.js 
1reducedmore.js:1821: TypeError: XML filter is applied to non-XML value []

Verified 1.9.1 and 1.9.2. (They no longer crash opt shells)
Comment 28 Al Billings [:abillings] 2010-05-01 10:55:00 PDT
Thanks, Gary.
Comment 29 Christian Holler (:decoder) 2013-01-04 13:23:53 PST
A testcase for this bug was automatically identified at js/src/tests/e4x/Regress/regress-561031.js.
Comment 30 Christian Holler (:decoder) 2013-01-04 15:57:10 PST
A testcase for this bug was automatically identified at js/src/tests/e4x/Regress/regress-561031.js.

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