Closed Bug 1479970 Opened Last year Closed 6 months ago

Tracelogger: enable compilation by default

Categories

(Core :: JavaScript Engine, enhancement, P2)

enhancement

Tracking

()

RESOLVED FIXED
mozilla68
Tracking Status
firefox63 --- wontfix
firefox68 --- fixed

People

(Reporter: denispal, Assigned: squib)

Details

Attachments

(3 files, 3 obsolete files)

The ultimate goal is to connect the tracelogger to the geckoProfiler and be able to toggle trace logging through the profiler start & stop routines.  The first step is to enable the compilation of the tracelogger by default to see if we can detect any possible regressions from the overhead checks.
Assignee: nobody → dpalmeiro
Priority: -- → P2
I disabled the TraceLogger in non-debug builds because it often showed up in profiles, IIRC the instrumentation in BaselineCompiler. It might be worth looking at that bug and we should also think about redesigning that to be faster.
I think the JS overhead might be caused by the fact that the TraceLogging mechanism is always enabled by default[1] instead of simply being enabled when the Trace recording is enabled.

We already have a mechanism in place for debugging, where toggling the Debugger causes the recompilation of existing scripts, and swap the Baseline code with the debugger-instrumented Baseline code.

I suggest to switch to a similar model for toggling the TraceLogger.

[1] https://searchfox.org/mozilla-central/rev/49e78df13e7a505827a3a86daae9efdf827133c6/js/src/jit/BaselineCompiler.cpp#493-497

Self-assigning this, since I'm looking into it. I'll probably have questions for folks in this bug once I get a bit farther along.

Assignee: dpalmeiro → jporter+bmo
Attached patch Non-working patch (obsolete) — Splinter Review

:nbp, I did some digging through the JS debugger code (I'm not super-familiar with it yet), and I think I have a rough idea of what you mean in comment 2. This is what I've managed so far, but it still crashes when capturing the profile. I just wanted to see if I was missing anything obvious that jumped out to you before I spend too much more time trying to figure it out myself. Thanks!

Attachment #9053421 - Flags: feedback?(nicolas.b.pierron)

To do this we need at least:

  1. Remove the perf hit from Baseline compilation (maybe by using a TL trampoline), this is why I disabled TL compilation by default initially. It showed up in many profiles.

  2. look at open TL fuzz bugs.

Comment on attachment 9053421 [details] [diff] [review]
Non-working patch

Review of attachment 9053421 [details] [diff] [review]:
-----------------------------------------------------------------

This sounds correct, however I am no expert in this debugging instrumentation, and there seems to be conflicts which have to be resolved:

https://searchfox.org/mozilla-central/source/js/src/jit/BaselineDebugModeOSR.cpp#693-695
Attachment #9053421 - Flags: feedback?(nicolas.b.pierron) → feedback+

(In reply to Jan de Mooij [:jandem] from comment #5)

To do this we need at least:

  1. Remove the perf hit from Baseline compilation (maybe by using a TL trampoline), this is why I disabled TL compilation by default initially. It showed up in many profiles.

  2. look at open TL fuzz bugs.

I'd talked with :denispal about this, and it sounded like we'd be ok (at least for part 1) if we were able to disable all the trace logging by default and then recompile with trace logging when we enable it. Would that not work? If you have any other ideas, just let me know. Thanks!

Flags: needinfo?(jdemooij)

We should consider making the tracelogger pref only check on start-up and require the user to restart to enable it. It will avoid the need to worry about toggling bugs or code invalidation problems. This includes the code in [1] that Jan referred to above.

This would give a chance to get TL into standard builds sooner. I think having a pref - even with a restart - will get far more use out of the tool than custom builds will. In the future, we could look at how to streamline this process and have recompile work, but currently recompile policies are always risky and difficult to maintain for a tool that is only used by a handful of people.

[1] https://searchfox.org/mozilla-central/rev/2c912888e3b7ae4baf161d98d7a01434f31830aa/js/src/jit/BaselineCompiler.cpp#326-329

Flags: needinfo?(jdemooij)

I'm not sure if we need anything too fancy here. The profiler already releases any JIT code when it starts and stops, so we can limit tracelogger compilation to only during this period. Doing this, the only extra overhead involved outside of profiling should just be a simple branch during compilation checking if the tracelogger is enabled.

The main problem, IIRC, is the jitted code that's on the activation stack when the profiler starts. This will not be instrumented and doesn't get released, so it messes up the tracelogger tree hierarchy because it doesn't get recorded. If there's any situation when we re-enter some jitted code that's on the activation stack (e.g. a cycle in the call graph) instead of recompiling it, then this is definitely a problem. If this is never the case, then something else may be going on and further investigation would be required.

(In reply to Denis Palmeiro [:denispal] from comment #9)

The main problem, IIRC, is the jitted code that's on the activation stack when the profiler starts. This will not be instrumented and doesn't get released, so it messes up the tracelogger tree hierarchy because it doesn't get recorded.

Currently when TL is enabled, we always emit the TL instrumentation in Baseline scripts [1] and use jump patching when TL is enabled/disabled. This is the part we need to fix before re-enabling: it's silly to generate a considerable amount of JIT code as part of each Baseline script for the handful of people using it occasionally.

[1] https://searchfox.org/mozilla-central/rev/a7315d78417179b151fef6108f2bce14786ba64d/js/src/jit/BaselineCompiler.cpp#1223-1255

(In reply to Jan de Mooij [:jandem] from comment #10)

Oh wait, I probably misread your message and you're aware of this :)

There's also the VM function instrumentation that's only generated when TL is enabled when we create the runtime:

https://searchfox.org/mozilla-central/rev/2c912888e3b7ae4baf161d98d7a01434f31830aa/js/src/jit/CodeGenerator.cpp#9011

Do we want to keep this code? A runtime pref we read on startup would work well for this too...

(In reply to Jan de Mooij [:jandem] from comment #11)

(In reply to Jan de Mooij [:jandem] from comment #10)

Oh wait, I probably misread your message and you're aware of this :)

There's also the VM function instrumentation that's only generated when TL is enabled when we create the runtime:

https://searchfox.org/mozilla-central/rev/2c912888e3b7ae4baf161d98d7a01434f31830aa/js/src/jit/CodeGenerator.cpp#9011

Do we want to keep this code? A runtime pref we read on startup would work well for this too...

I think we should keep it, but I'll test it out on my end. Even though that event is not enabled right now, I think it could be useful information and we should probably enable it.

I agree a pref should be a good stepping stone for now to at least make it usable without a compilation flag. The ideal end result should be simply removing the lines here: https://searchfox.org/mozilla-central/rev/a7315d78417179b151fef6108f2bce14786ba64d/js/src/vm/TraceLogging.cpp#144-153 which should disable any tracelogger instrumentation in jitted code. But there are some problems right now preventing us from doing so, mainly we hit this assert often: https://searchfox.org/mozilla-central/rev/a7315d78417179b151fef6108f2bce14786ba64d/js/src/vm/TraceLogging.cpp#629 because the events on the graphStack do not line up.

Thanks for all the feedback! I'll try and get a patch together to turn this into a pref tomorrow.

This is a quick patch to sketch out how a pref would look for enabling/disabling Tracelogger. There are some tradeoffs to using a pref vs an environment variable:

+ A pref is more discoverable (you don't have to remember the exact spelling to use it)
+ A pref is easier to set once for a given profile and always have it on
- An environment variable is easier to use for one-off tests
- An environment variable makes it clearer that you need to restart to enable the tracelogger

One question I have is whether the ContextOptions is the right place to store this flag. It does mean we need a JSContext to read the flag from, and maybe we just want a global variable somewhere.

As a side note, this patch is slightly wrong, since the pref value is updated immediately, so JSContexts created afterwards will have the new value, possibly breaking stuff. The right thing is probably to read it once and cache the value.

Attachment #9053421 - Attachment is obsolete: true
Attachment #9054359 - Flags: feedback?(tcampbell)
Attachment #9054359 - Flags: feedback?(dpalmeiro)
Comment on attachment 9054359 [details] [diff] [review]
Partial patch to add a pref for Tracelogger

Review of attachment 9054359 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good, thanks Jim!

::: js/src/vm/TraceLogging.cpp
@@ +38,5 @@
> +  JSContext* cx = TlsContext.get();
> +  if (!cx->options().traceLoggerEnabled()) {
> +    return false;
> +  }
> +

I think we should move this condition before the MOZ_LIKELY one above.  It will be slightly more expensive during tracing, but when the tracelogger is not enabled it should be one less branch to predict.  I wonder if we should also have this function take a JSContext* as an argument instead of getting it from the TlsContext.  Most callers will likely already have one available, and it could be quite expensive to constantly query TlsContext for it.  Something to consider if we find this part to have a performance impact.
Attachment #9054359 - Flags: feedback?(dpalmeiro) → feedback+
Comment on attachment 9054359 [details] [diff] [review]
Partial patch to add a pref for Tracelogger

Review of attachment 9054359 [details] [diff] [review]:
-----------------------------------------------------------------

Seems like a reasonable direction to follow what the fuzzing flags do. We'll want to make sure that we can indicate to the profiler if tracelogger is unavailable so we can potentially have a help message.

I think ContextOptions is probably still the right place to have the flag since the decisions are traced through to the Runtime.

One thing that is a little annoying is that TraceLogger looks like it would always create TraceLoggerThreadState. It would be nice if we didn't create it if the context we are calling TraceLoggerForThread has trace-logging disabled.

Perhaps we just want to re-work js::TraceLoggerForCurrentThread to turn maybecx into a non-null cx immediately and to check the context option there before we EnsureThreadState.
Attachment #9054359 - Flags: feedback?(tcampbell) → feedback+
Attached patch Mostly-working patch (obsolete) — Splinter Review

This patch should work right, except that it turns out I can't use a pref, or at least, I can't figure out how to use a pref: unfortunately, the current pref is loaded too late, so we get a couple JSContexts created with the default value before prefs.js (I assume?) gets loaded and the pref set to its proper value.

Thus, I think the only solution here is an environment variable. This also makes it really easy to ensure that we only read the flag once. I'll work on this next, but it's awfully late here...

Attachment #9054359 - Attachment is obsolete: true

(In reply to Ted Campbell [:tcampbell] from comment #16)

Seems like a reasonable direction to follow what the fuzzing flags do. We'll
want to make sure that we can indicate to the profiler if tracelogger is
unavailable so we can potentially have a help message.

That shouldn't be too hard. We'd need something that the profiler add-on can read, right?

One thing that is a little annoying is that TraceLogger looks like it would
always create TraceLoggerThreadState. It would be nice if we didn't create
it if the context we are calling TraceLoggerForThread has trace-logging
disabled.

I think my current patch avoids creating TraceLoggerThreadState if the flag is disabled. I'll double-check tomorrow though.

This patch enables compilation of the tracelogger by default on nightly builds
as well as providing an environment variable (JS_TRACE_LOGGING) to enable or
disable tracelogger instrumentation when compiling Javascript. This helps to
reduce the performance impact of the Tracelogger code when not in use. In the
future, this could be improved to recompile the JS with/without Tracelogger
instrumentation when toggling Tracelogger support.

Attachment #9055724 - Attachment is obsolete: true

This only had one use is inconsistent with other tracelogger users.

Avoid any risk of running non-trivial line-number or error reporting
code.

Pushed by tcampbell@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/bd6762543efe
Remove IonBuilder::traceLogger(). r=jandem
https://hg.mozilla.org/integration/autoland/rev/2cc7599b9e92
Use early exits in AutoFrontendTraceLog. r=jandem
https://hg.mozilla.org/integration/autoland/rev/32342cbe673a
Enable building Tracelogger by default; r=tcampbell
You need to log in before you can comment on or make changes to this bug.