Closed Bug 599009 Opened 14 years ago Closed 14 years ago

JaegerMonkey very slow when executing Javascript code obfuscated with JS packers.

Categories

(Core :: JavaScript Engine, defect, P1)

x86
Windows 7
defect

Tracking

()

RESOLVED FIXED
Tracking Status
blocking2.0 --- beta8+

People

(Reporter: phi2x, Assigned: bzbarsky)

References

()

Details

(Whiteboard: fixed-in-tracemonkey)

Attachments

(9 files)

User-Agent:       Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0b7pre) Gecko/20100923 Firefox/4.0b7pre
Build Identifier: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0b7pre) Gecko/20100923 Firefox/4.0b7pre

I am the author of an Amstrad CPC 8-bit computer emulator, entirely written in Javascript. You can use it here: http://www.cpcbox.com/

I tested it on the latest Minefield build, and as you can see performance is not so great (less than 15fps on a Core2@3GHz).

The pre-production version of cpcbox, which happens to be exactly the same as the one in http://www.cpcbox.com/, except that the javascript has not been minified & obfuscated has completely different performance!
On that non minified version, I run around 75fps on the same setup!

That underlines a big issue with JaegerMonkey which is that those popular Javascript minifiers/obfuscators impact performance big time (ie: 500% slower on cpcbox when minified).
That issue is not found under Chrome, performance is equal on both the unminified and minified versions.
Under Opera, there is some small impact (around 20% slower for the minified version).

To minify & obfuscate cpcbox, I used Javascript utility v2:
http://jsutility.pjoneil.net/

Reproducible: Always

Steps to Reproduce:
1. Go to http://www.cpcbox.com/
2. Look at how bad it performs.
3. With the same JS code but unminified, it runs at 75+fps with Minefield on Core2@3GHz.
Actual Results:  
Javascript code packed with popular JS packers performs very poorly on JaegerMonkey.

Expected Results:  
JaegerMonkey is expected to behave with same performance on packed Javascript code than with the same Javascript code unpacked.
Google Chrome's Javascript engine don't suffer any performance loss with packed Javascript.
Assignee: nobody → general
Component: General → JavaScript Engine
Product: Firefox → Core
QA Contact: general → general
The minifier/obfuscator doesn't, by any chance, insert 'with' statements does it?
It doesn't.  What it does is convert all the stuff to a string and then eval the string....  The relevant code is http://www.cpcbox.com/cpcbox.min.js (for the minified version).

I'll attach versions of the page (not standalone; still references some files off the original site) that reference both the minified file and the "unminified" (by simply grabbing the string passed to eval and sourcing that as the JS) file.  The latter performs much much faster on my machine, so the eval in global scope is somehow to blame.
Attached file The minified js
Attached file "unminified" js
Certainly reproducible...  ;)

On my hardware, Chrome is at 25ps on both testcases.
Status: UNCONFIRMED → NEW
blocking2.0: --- → ?
Ever confirmed: true
Results from running it:

mozilla% ./js/src/opt-obj/js ~/test.js
No eval: 251
eval: 317
mozilla% ./js/src/opt-obj/js -m ~/test.js
No eval: 48
eval: 89
mozilla% ./js/src/opt-obj/js -j ~/test.js
No eval: 20
eval: 19

So both interp and methodjit take a performance hit on the eval version, but the methodjit hit is a bigger fraction of runtime.  Note that in this case methodjit is a 2x slowdown, in the shell.  Browser numbers are _very_ different; testcase plus numbers coming up.
Running this in a current m-c nightly, I get:

Both jits off:
No eval: 249
eval: 303

Methodjit only:
No eval: 26
eval: 515

Both jits on:
No eval: 19
eval: 22
And I get similar numbers in a current tracemonkey nightly.

Though my local build from http://hg.mozilla.org/tracemonkey/rev/33b47507d2f6 seems to do about as well as shell on the attached small testcase... but is still slow on the big emulator testcase.  So maybe the reduction isn't right.  :(  In any case, that 20x slowdown with eval + methodjit is worth looking into.
Profiling the slow case, I get 80% of the time spent under ic::SetPropDumb.  This is mostly calling js_SetPropertyHelper, which is doing a lookup (interestingly, this part does NOT call into DOM code), calling js_NativeSet, etc.  Most of the time is SetPropDumb self time, SetPropertyHelper self time, js_LookupPropertyWithFlags self time.

There's a lot more time spent in mjit-generated code than in the fast case too (at least 2x as much time as for the entirety of the fast case)
blocking2.0: ? → beta8+
The global variable accesses are not getting optimized. I tried changing the "++z" in the shell test case to "z = 6" and "z", and all three cases showed a slowdown. If I change it to "y" (not a global here), there is no slowdown.
Yeah.  The only question is whether the shell testcase accurately reflects the problem in the web testcase... I guess we fix it and see?
Depends on: 601256
With the patch for bug 601256, I now see the following numbers:

On the "Equivalent browser testcase" attached in this bug, methodjit only is something like this:

  No eval: 45
  eval: 61

which is almost identical to what it is in shell.

On the HTML testcases attached, I get about 42fps now on the unminified (both before and after bug 601256).  On minified I get 5fps before and 20fps after.

Chrome is at 35fps on both minified and not.

So that helped a lot, but we still have a 2x slowdown in the eval version from somewhere....
Profiling, it looks like in 5 secs runtime the eval version has 34k samples under nsGlobalWindow::RunTimeout.  The non-eval one has 22k samples.

Comparing the two profiles, the non-eval version spends (all percentages are of JS time):

  20% in mjit-generated code.
  50% in tracejit-generated code.
  12% putImageData on the canvas
   3% in js_Interpret
   3% entering/leaving trace
   5% stubs::Equal
   4% stubs::NewArray
   2% stubs::TableSwitch

The eval version, on the other hand, is (and keep in mind that these are percentages of a bigger number now):

  47% in mjit-generated code 
  21% stubs::GetGlobalName (complete with calling XPC_WN_Helper_GetProperty and
      ensuing xpconnect gunk)
  20% stubs::SetElem<0> (half itself, half obj_setProperty on typed arrays)
   5% stubs::SetName
   4% putImageData on the canvas
   2% stubs::Equal
   2% stubs::NewArray
   2% stubs::TableSwitch

So the biggest issues seem to be that we're not tracing here for some reason, and that GetGlobalName is hitting up the class getters on the window.  Is that the GLOBAL vs GNAME thing mentioned in bug 601256?
In particular, is the GetGlobalName behavior specific to eval, or just a general JM thing that tracing is just hiding in the faster testcase?
(In reply to comment #15)
>   21% stubs::GetGlobalName (complete with calling XPC_WN_Helper_GetProperty and
>       ensuing xpconnect gunk)

Apparently we don't IC this. Do we know why? Does it have a getter? (It would have to be a getter that the tracer can somehow optimized really well; JM doesn't IC getters yet?) Some other reason?

>   20% stubs::SetElem<0> (half itself, half obj_setProperty on typed arrays)

This is bug 594247.
Depends on: 594247
If I disable tracejit, the minified testcase still runs at 20fps; unminified runs at 27fps.  So it's not just the tracer hiding stuff.

In particular, the unminified testcase does NOT hit stubs::GetGlobalName even without tracejit, according to the profile.

> Does it have a getter?

The window object has a class getter, so technically all properties on it have getters...  But I think we do some magic for vars normally that avoids those getters?
vars in eval look ok to me.  But the things that have that getter hook seem to be functions.  And indeed, consider this testcase:

  function g() {}
  eval("function f() { }");

when I run that in browser, I first see the "g" prop added with null getter and
setter, via js::Compiler::defineGlobals calling js_DefineNativeProperty with
property stub getter/setter.

Then I see the "f" prop added with the class-default getter and setter, via
js::mjit::stubs::DefFun calling JSObject::setProperty, which calls
js_SetProperty, which lands us in the normal js_SetPropertyHelper codepath and
picks up the class-default flags.
The relevant comment in DefFun sems to be:

     * We deviate from 10.1.2 in ECMA 262 v3 and under eval use for function
     * declarations JSObject::setProperty, not JSObject::defineProperty, to
     * preserve the JSOP_PERMANENT attribute of existing properties and make
     * sure that such properties cannot be deleted.
If I just force doSet to false in DefFun, though, I still see us calling into the window getter.  So maybe there's something else going on too.  Will dig more.
Ah, and of course there's similar code in js::Interpret....

If I force doSet to false _there_ as well, I get sweet 42fps goodness for the minified version, just like the non-minified.  Presumably we start tracing it and all, now that we no longer hit nasty xpconnect on every single global function name get.

For comparison, Safari 5 is at 30fps, Chrome 7 dev at 34 fps, Opera 10.6 at 40fps.
There's a "parade of stupid" going on here. NULL to the JS API down through ObjectOps::defineProperty for a getter or setter means "use the class default". But NULL below that in the shape->raw[GS]etter members means PropertyStub was used (which is not the class getProperty or setProperty for notorious objects such as windows).

We really do not need the class-default getter and setter, Class::getProperty and Class::setProperty, to see any functions. Indeed the interpreter gets this right (this change was made for TM back in its infancy, IIRC):

    ok = doSet
         ? parent->setProperty(cx, id, &rval, script->strictModeCode)
         : parent->defineProperty(cx, id, rval, PropertyStub, PropertyStub, attrs);

So is the fix just to change stubs::InitElem so it passes PropertyStub not NULL in this line?

        if (!obj->defineProperty(cx, id, rref, NULL, NULL, JSPROP_ENUMERATE))
            THROW();
/be
I filed bug 602342 on the getters/setters in JS API vs. internal API/field-value encoding overloading of NULL.

/be
Sorry, comment 23 went off the beam looking at SetElem -- but to get back to bz's point, we should be able to avoid giving ad-hoc properties created by assignment (or eval of a function definition) the class-default getter and setter. It's an API break, but worth it -- and it must not have security consequences in our new compartment/wrapper world.

/be
> Indeed the interpreter gets this right

"No", since the function prop is enumerable, so doSet is true.
This makes the minified case just as fast as the unminified one (on my machine, 20% faster than v8, 50% faster than jsc, for those keeping track).

Not sure what a good way to write a test for this is...

Igor, can you take a look to make sure I didn't miss something in how this is supposed to work here?
Assignee: general → bzbarsky
Status: NEW → ASSIGNED
Attachment #481419 - Flags: review?(igor)
Priority: -- → P1
Attachment #481419 - Flags: review?(igor) → review+
Pushed http://hg.mozilla.org/tracemonkey/rev/30c33853066d

This is so fixed.  ;)
Whiteboard: fixed-in-tracemonkey
And http://hg.mozilla.org/tracemonkey/rev/3ffc86637e36 to fix the typo in the stubs::DefFun assert.
(In reply to comment #26)
> > Indeed the interpreter gets this right
> 
> "No", since the function prop is enumerable, so doSet is true.

Yeah, that went off the beam as noted.

Great work, bz!

/be
Hey, dmandelin did the tough part!
Comment on attachment 481419 [details] [diff] [review]
Per discussion with brendan

>+             parent->isCall() &&
>+             (old = ((Shape *) prop)->attributes(),
>+              !(old & (JSPROP_GETTER|JSPROP_SETTER)) &&

Just took a look at the patch in detail, noticed this last line is an unnecessary test. How can a Call object have accessor properties?

Igor, does this date from ancient times when Call objects escaped to script?

/be
(In reply to comment #32)
> Comment on attachment 481419 [details] [diff] [review]
> Per discussion with brendan
> 
> >+             parent->isCall() &&
> >+             (old = ((Shape *) prop)->attributes(),
> >+              !(old & (JSPROP_GETTER|JSPROP_SETTER)) &&
> 
> Just took a look at the patch in detail, noticed this last line is an
> unnecessary test. How can a Call object have accessor properties?

This is for the case where pobj is the global object or an object on its proto chain. Never mind (although I may refactor a bit to tighten the logic, and also avoid uninitialized uint32 old -- and make that uintN).

/be
hg qdiff -w next.

/be
Attachment #481581 - Flags: review?(bzbarsky)
Comment on attachment 481581 [details] [diff] [review]
followup nit-picks

r=me if you make that JS_ASSERT_IF unconditional now that oldAttrs is always initialized.

Btw... maybe this should all be a shared inline helper method so we only have one copy?  ;)
Attachment #481581 - Flags: review?(bzbarsky) → review+
Thanks, will fix.

Tons of jsinterp.cpp duplication in methojit/StubCalls.cpp -- I'm not gonna morph this bug for that. There's a bug on file, filed by jorendorff IIRC.

/be
http://hg.mozilla.org/tracemonkey/rev/3dc1c262f3b6

This is a fix after all. Comment 32 was right, the JSPROP_GETTER | JSPROP_SETTER testing makes no sense for Call object properties -- but it is require for global properties that pre-exist and are not JSPROP_READONLY (i.e., we got past the CheckRedeclaration).

Igor, could you retroactively review my followup, linked here? Thanks.

/be
Backed out, there's more to do and I'll file a new bug for it.

http://hg.mozilla.org/tracemonkey/rev/fa8b0ad3e3e6 (back out 3dc1c262f3b6)

/be
Filed bug 602621.

/be
http://hg.mozilla.org/mozilla-central/rev/30c33853066d
Status: ASSIGNED → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.