776798 - IonMonkey/baseline compiler disabled for code called from nsITimerCallback in JSM or XPCOM component

Status: RESOLVED FIXED

(Core :: XPConnect, defect)

Description

[Simon Kornblith]

Attachment: XPI demonstrating issue

When a JavaScript function is called from an nsITimerCallback in a JSM or XPCOM component (but not in a chrome window), the function and everything it calls appear to be interpreted rather than JITed.

The attached XPI provides a means to test how long it takes to run a test callback fired from an nsITimer in a JSM and compare it with how long it takes to run the same callback from setTimeout on the hidden DOM window in a JSM, from an nsITimer in the window, and from setTimeout in the window. The test callback makes 1,000,000 function calls. On my system, it takes about 13x as long to run when interpreted as it does with the JIT.

Steps to reproduce:

1. Install the attached XPI
2. Open chrome://jit-test/content/test.xul
3. Compare reported time for "Test nsITimer from JSM" with times reported for other buttons

To verify that this is due to lack of JITing:

4. Install Brian Hackett's JIT Inspector (https://addons.mozilla.org/EN-us/firefox/addon/jit-inspector/)
5. Go to Tools->Web Developer->JIT Inspector and click "Start Profiling"
6. Click "Test nsITimer from JSM" and then one of the other buttons (JIT inspector doesn't seem to show the code unless it has been run with the JIT at least once)
7. Click "Stop Profiling"
8. Observe that the loop is interpreted ~1,000,000 times and run with the methodjit ~1,000,000 times.
9. Click "Start Profiling"
10. Click any button but "Test nsITimer from JSM"
11. Observe that the code is run with the methodjit ~1,000,000 times.

I can reproduce with both Firefox 14 and the current trunk.

Apologies if this is already known or reported elsewhere, but it seems like a large and avoidable performance pitfall for XPCOM/JSM code that uses an nsITimer instead of setTimeout.

Comment 1

[Simon Kornblith]

I was curious what was causing this, and after looking through the code, I think I _might_ understand it. mozJSComponentLoader::ReallyInit creates a JSContext for the JSM that doesn't apply JS_OPTION_METHODJIT even if javascript.options.methodjit.chrome is set to true. (It also lacks other options like JSOPTION_STRICT, JSOPTION_WERROR, and JSOPTION_RELIMIT that are set on nsJSContexts by nsJSContext::JSOptionChangedCallback.) If one makes a call from a ChromeWindow to a JSM, then the function gets called with the ChromeWindow's context (I guess?), so JS_OPTION_METHODJIT is enabled. If the JSM executes JavaScript on load, or if it makes a JS->Native->JS call, then the JavaScript gets called with the JSM's context, which lacks JS_OPTION_METHODJIT.

The JIT can be rescued for nsITimerCallbacks like so:

var useMethodjit = Components.utils.methodjit;
timer.initWithCallback({"notify":function() {
    Components.utils.methodjit = useMethodjit;
    runCallback();
}}, 0, Components.interfaces.nsITimer.TYPE_ONE_SHOT);

This seems unintuitive, but perhaps there is a reason for it? If not, I'm willing to try my hand at a patch (assuming my understanding above is vaguely correct).

Comment 2

[Boris Zbarsky [:bzbarsky]]

At one point this was semi-purposeful, iirc...

Comment 3

[David Teller [:Yoric] - still alive but not very active]

The amount of code that uses a nsITimer for scheduling purpose is growing up, and most users are not aware of this bug, so I have the feeling that this bug will be rather hurtful in the near future.
It would be great if someone could fix this bug.

Comment 4

[Boris Zbarsky [:bzbarsky]]

So what behavior do we want here?  Do we want it to follow the jit prefs the same way that chrome windows do, or always have jit on, or something else?

Comment 5

[Bobby Holley (:bholley)]

I filed bug 880330 to make our jit flag situations sane.

Comment 6

[David Teller [:Yoric] - still alive but not very active]

Note that the workaround mentioned in comment 1 doesn't work anymore, for some reason.

Comment 7

[Boris Zbarsky [:bzbarsky]]

Probably because there is no more methodjit, hence no Components.utils.methodjit?

Comment 8

[David Teller [:Yoric] - still alive but not very active]

Well, this could explain that. I haven't taken the time to figure out why it didn't work anymore.

Comment 9

[Till Schneidereit [:till]]

IIUC, this affects all JITs? If so, we should rename the bug to talk about IonMonkey and baseline.

Comment 10

[Till Schneidereit [:till]]

Running all timer-triggered code in JS modules in the interpreter only sounds pretty bad to me. There must be lots of functions/loops in modules that get executed more than 10 times and thus would be baseline-compiled.

Implementing bug 880330 is certainly the right long-term fix to this, but maybe we should also do a short-term band-aid, like copying the relevant options from the context that's active when the module is created?

Comment 11

[Bobby Holley (:bholley)]

(In reply to Till Schneidereit [:till] from comment #10)
> Implementing bug 880330 is certainly the right long-term fix to this, but
> maybe we should also do a short-term band-aid, like copying the relevant
> options from the context that's active when the module is created?

No, I don't think that's a very good idea. I just need to do the work here. I'll try to get to it soon.

Comment 12

[Jan de Mooij [:jandem]]

Bug 939562 (should be in today's Nightly) fixed the main problem here, I now get the same numbers for "Test nsITimer from JSM" as for the other buttons.

I noticed that the script (and a lot of other chrome code) is not compile-and-go though, so it's not Ion-compiled, only Baseline-compiled. Next week I'll fix IonMonkey to compile non-CNG functions, that should be pretty straight-forward (famous last words). Keeping this bug open for that.

But anyway, nsITimerCallback code should now run as fast as the rest of your JS; that part is fixed.

Comment 13

[Bobby Holley (:bholley)]

Awesome, thanks Jandem!

Comment 14

[Florian Bender]

(In reply to Jan de Mooij [:jandem] from comment #12)
> Next week I'll fix IonMonkey to compile non-CNG functions, that should be
> pretty straight-forward (famous last words). 

Indeed ;) Did you have time yet to look at this? (Feel free to unassign.)

Comment 15

[Emanuel Hoogeveen [:ehoogeveen]]

Is this fixed now that bug 1045529 has landed?

Comment 16

[Bobby Holley (:bholley)]

Over to jandem for verification of status wrt comment 12.

Comment 17

[Jan de Mooij [:jandem]]

I installed the attached add-on and ran some tests.

Numbers (in ms) for Firefox 29 / Firefox 30 / Nightly

nsITimer from JSM:    87 / 19 / 1
setTimeout from JSM:  19 / 20 / 1
nsITimer in Window:   19 / 18 / 1
setTimeout in Window: 18 / 20 / 0

Bug 939562 (in Firefox 30) fixed "nsITimer from JSM" to be as fast as the rest, by enabling Baseline compilation for it.

With bug 1045529 (in Firefox 34), we can Ion compile non-CNG scripts, that's why Nightly is faster than 30.