Closed
Bug 1072906
Opened 10 years ago
Closed 10 years ago
Tracelogger: Add way to enable/disable logging in IM/Baseline
Categories
(Core :: JavaScript Engine: JIT, defect)
Tracking
()
RESOLVED
FIXED
mozilla36
People
(Reporter: h4writer, Assigned: h4writer)
References
Details
Attachments
(2 files, 3 obsolete files)
32.83 KB,
patch
|
jandem
:
review+
|
Details | Diff | Splinter Review |
7.68 KB,
patch
|
bbouvier
:
review+
|
Details | Diff | Splinter Review |
There are two solutions for this: 1) Like SPS profiler, recompile upon enable/disable 2) Add the code to log already, but behind a jump which we patch whenever we want enable/disable the logging. I think (1) will be the easiest.
Assignee | ||
Comment 1•10 years ago
|
||
TODO: 1) Add option to force createTextId for scripts. 2) Find solution to not overflow textId list 3) Expose the TL_XXX enum to Debugger
Assignee: nobody → hv1989
Assignee | ||
Comment 2•10 years ago
|
||
Make it possible to adjust logged items during execution.
Attachment #8501097 -
Attachment is obsolete: true
Assignee | ||
Comment 3•10 years ago
|
||
Tracelogger has different things it can log. And it can be toggled which things should get logged and which shouldn't. The types are an enum in c code. But I should have this for Debugger too.
Now I was wondering where the best place was to add this?
Not sure I understand the difference between "Debugger"/"DebuggerScript"/"DebuggerSource"/"DebuggerFrame"/"DebuggerObject"/"DebuggerEnv" to make an informed decision.
The current list is something like:
> _(BaselineCompilation) \
> _(Engine) \
> _(GC) \
> _(GCAllocation) \
> _(GCSweeping) \
> _(Internal) \
> _(Invalidation) \
> _(IrregexpCompile) \
> _(IrregexpExecute) \
> _(IonCompilation) \
> _(IonCompilationPaused) \
> _(IonLinking) \
> _(MinorGC) \
> _(ParserCompileFunction) \
> _(ParserCompileLazy) \
> _(ParserCompileScript) \
> _(Scripts) \
> _(VM) \
> _(Bailout) \
> \
> /* Specific passes during ion compilation */ \
> _(FoldTests) \
> _(SplitCriticalEdges) \
> _(RenumberBlocks) \
> _(ScalarReplacement) \
> _(DominatorTree) \
> _(PhiAnalysis) \
> _(MakeLoopsContiguous) \
> _(ApplyTypes) \
> _(ParallelSafetyAnalysis) \
> _(AliasAnalysis) \
> _(GVN) \
> _(LICM) \
> _(RangeAnalysis) \
> _(LoopUnrolling) \
> _(EffectiveAddressAnalysis) \
> _(EliminateDeadCode) \
> _(EdgeCaseAnalysis) \
> _(EliminateRedundantChecks) \
> _(GenerateLIR) \
> _(RegisterAllocation) \
> _(GenerateCode)
Note: for now debugger will only use Scripts, but it can use more already. This would enable it to enable more reporters.
Flags: needinfo?(nfitzgerald)
Assignee | ||
Updated•10 years ago
|
Attachment #8503087 -
Flags: review?(jdemooij)
Comment 4•10 years ago
|
||
(In reply to Hannes Verschore [:h4writer] from comment #3) > Tracelogger has different things it can log. And it can be toggled which > things should get logged and which shouldn't. The types are an enum in c > code. But I should have this for Debugger too. > > Now I was wondering where the best place was to add this? > Not sure I understand the difference between > "Debugger"/"DebuggerScript"/"DebuggerSource"/"DebuggerFrame"/ > "DebuggerObject"/"DebuggerEnv" to make an informed decision. I think this should be exposed on Debugger's prototype directly, something like: Debugger.prototype.startTraceLogging(config) Debugger.prototype.endTraceLogging() Usage: dbg.startTraceLogging({ GC: true, minorGC: true, ... }); I'd like to hear what Jim thinks as well.
Flags: needinfo?(nfitzgerald) → needinfo?(jimb)
Assignee | ||
Comment 5•10 years ago
|
||
Ah interesting. I actually have three functions: // Enable/disable certain hooks. This prepares baseline/ionmonkey so it can emit these log items. // This is invalidates ionmonkey code and is quite expensive. // (This doesn't start logging, but will decrease performance a little bit. (barely noticeable). // It is the idea that you can do that as soon as you go to this devtool. And disable as soon as // you leave that tab.) dbg.enableTraceItem(dbg.TraceLogger_GC); // Start/stop logging. Because we have prepared everything, enabling/disabling is not disruptive and doesn't take a lot of time. dbg.startTraceLogging(); dbg.endTraceLogging(); the name of "enableTraceItem" isn't quite good yet. What about: dbg.prepareTraceLogger({ GC: true, minorGC: true, ... }); Which would be closer to your idea...
Comment 6•10 years ago
|
||
What does splitting out the options from the starting of logging provide? It seems to me like one would pretty much always want to do both at the same time.
Assignee | ||
Comment 7•10 years ago
|
||
(In reply to Nick Fitzgerald [:fitzgen] from comment #6) > What does splitting out the options from the starting of logging provide? It > seems to me like one would pretty much always want to do both at the same > time. For performance measurement this is quite handy to have them separate. You don't want to interfere with performance by invalidating all IonMonkey code every time you enable/disable tracelogger. E.g. if you use start/endTraceLogging in a hot function, to only see code corresponding to that function.
Comment 8•10 years ago
|
||
Comment on attachment 8503087 [details] [diff] [review] Dynamically toggle logged ids in Baseline and IonMonkey Review of attachment 8503087 [details] [diff] [review]: ----------------------------------------------------------------- Looks good but some questions below. Also do we need similar changes for Ion? ::: js/src/jit/BaselineCompiler.cpp @@ +773,5 @@ > + Register loggerReg = regs.takeGeneral(); > + Register scriptReg = regs.takeGeneral(); > + > + masm.Push(loggerReg); > + masm.movePtr(ImmPtr(logger), loggerReg); Can you move this inside the jumped-over code? 99.9% of the time TL will be disabled, so I'd prefer doing no extra work in that case. @@ +780,5 @@ > + Label noScriptStart; > + tlScriptStartToggleOffset_ = masm.toggledJump(&noScriptStart); > + masm.Push(scriptReg); > + tlScriptTextIdLabel_ = masm.movWithPatch(ImmWord(uintptr_t(TL_Scripts)), scriptReg); > + masm.tracelogStart(loggerReg, scriptReg); `force = true` here too? @@ +786,5 @@ > + masm.bind(&noScriptStart); > + > + // Engine start. > + Label noEngineStart; > + tlEngineStartToggleOffset_ = masm.toggledJump(&noEngineStart); Do we really need to toggle the script and engine separately? How much overhead is there from logging both if TL is enabled? ::: js/src/jit/BaselineJIT.h @@ +361,5 @@ > > void toggleSPS(bool enable); > > + void toggleTLScript(JSRuntime *runtime, JSScript *script, bool enable); > + void toggleTLEngine(bool enable); Nit: TraceLogger or TraceLogging instead of TL is longer but clearer. @@ +415,5 @@ > > +void > +ToggleBaselineTLScripts(JSRuntime *runtime, bool enable); > +void > +ToggleBaselineTLEngine(JSRuntime *runtime, bool enable); Same here. ::: js/src/vm/Debugger.cpp @@ +3044,5 @@ > + THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > + if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) > + return false; > + > + uint32_t id = args[0].toInt32(); We should add some jit-tests. Also the fuzzers probably won't like the unchecked toInt32() here :)
Attachment #8503087 -
Flags: review?(jdemooij)
Assignee | ||
Comment 9•10 years ago
|
||
Adjust enableTraceItem to prepareTraceLogger like suggested in comment 4/5
Attachment #8504066 -
Flags: review?(benj)
Assignee | ||
Comment 10•10 years ago
|
||
Comment on attachment 8504066 [details] [diff] [review] Part 2: add prepareTraceLogger Review of attachment 8504066 [details] [diff] [review]: ----------------------------------------------------------------- Maybe I should also use prepareTraceLogging, instead of prepareTraceLogger? ::: js/src/vm/Debugger.cpp @@ +3043,3 @@ > { > THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) s/enableTraceItem/prepareTraceLogger
Comment 11•10 years ago
|
||
Comment on attachment 8504066 [details] [diff] [review] Part 2: add prepareTraceLogger Review of attachment 8504066 [details] [diff] [review]: ----------------------------------------------------------------- Nice that we're having this in the debugger! \o/ I think there are a few things to improve first, in this patch. ::: js/src/vm/Debugger.cpp @@ +3043,3 @@ > { > THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) yes, twice above. Also, how about "setupTraceLogger"? @@ +3044,5 @@ > THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) > return false; > > + RootedValue arg(cx, args[0]); args[0] is used only once, please inline its use: RootedObject props(cx, ToObject(cx, args[0])); @@ +3050,5 @@ > + if (!props) > + return false; > + > + AutoIdVector ids(cx); > + if (!GetPropertyKeys(cx, props, JSITER_OWNONLY | JSITER_SYMBOLS, &ids)) you skip symbols in the for loop, so no need to include them in the GetPropertyKeys here @@ +3053,5 @@ > + AutoIdVector ids(cx); > + if (!GetPropertyKeys(cx, props, JSITER_OWNONLY | JSITER_SYMBOLS, &ids)) > + return false; > + > + size_t n = ids.length(); could you put it in the loop initializers? @@ +3056,5 @@ > + > + size_t n = ids.length(); > + > + for (size_t i = 0; i < n; i++) { > + if (!JSID_IS_STRING(ids[i])) with the above change, can we MOZ_ASSERT instead of skipping on test, here? @@ +3067,5 @@ > + > + uint32_t textId = TLStringToTextId(linear); > + > + if (!TLTextIdIsToggable(textId)) { > + args.rval().setBoolean(false); This means that if we toggle a few existing ids and then a non-existing one, the previous existing ones will be activated. I think we'd prefer to either activate them all, or none of them, what do you think? That would require a vector to store them, though, but that looks finer than such an API. An alternative would be to return an array of the effectively activated text-ids. @@ +3079,5 @@ > + > + if (textId == TL_Scripts) > + jit::ToggleBaselineTLScripts(cx->runtime(), true); > + if (textId == TL_Engine) > + jit::ToggleBaselineTLEngine(cx->runtime(), true); These 4 lines above look like they belong to TraceLogEnableTextId; caller shouldn't have to worry about this here. @@ +3082,5 @@ > + if (textId == TL_Engine) > + jit::ToggleBaselineTLEngine(cx->runtime(), true); > + } > + > + ReleaseAllJITCode(cx->runtime()->defaultFreeOp()); Ha, so doing Debugger.prepaceTraceLogger({}); right now will be an effective way to delete jit code. Can you take into account the fact that we've added new text-ids that were not activated beforehands? ::: js/src/vm/TraceLoggingTypes.cpp @@ +8,5 @@ > + > +#include "jsstr.h" > + > +uint32_t > +TLStringToTextId(JSLinearString *str) Why not using a hash-table?
Attachment #8504066 -
Flags: review?(benj)
Assignee | ||
Comment 12•10 years ago
|
||
(In reply to Jan de Mooij [:jandem] from comment #8) > Comment on attachment 8503087 [details] [diff] [review] > Dynamically toggle logged ids in Baseline and IonMonkey > > Review of attachment 8503087 [details] [diff] [review]: > ----------------------------------------------------------------- > > Looks good but some questions below. Also do we need similar changes for Ion? No, we invalidate the IonScript for IonMonkey. During the recompile the right hooks get added. > @@ +780,5 @@ > > + Label noScriptStart; > > + tlScriptStartToggleOffset_ = masm.toggledJump(&noScriptStart); > > + masm.Push(scriptReg); > > + tlScriptTextIdLabel_ = masm.movWithPatch(ImmWord(uintptr_t(TL_Scripts)), scriptReg); > > + masm.tracelogStart(loggerReg, scriptReg); > > `force = true` here too? The "force" is used when we do "masm.tracelogStart" with a specific textId. When that particular textId is disabled masm.traceLogStart will not emit anything. The "force" is to make sure we do generate the code. Here it is used with a Register. In that case we can't check beforehand if that particular textId is enabled. So we always emit code. As a result that variant has no "force" variable. It is always emitted. > @@ +786,5 @@ > > + masm.bind(&noScriptStart); > > + > > + // Engine start. > > + Label noEngineStart; > > + tlEngineStartToggleOffset_ = masm.toggledJump(&noEngineStart); > > Do we really need to toggle the script and engine separately? How much > overhead is there from logging both if TL is enabled? We only want to log which item is enabled. So it should be able to toggle them separately. Though there is another check inside "logTimestamp". So we could toggle both on/off and make sure only one of them gets logged. Which I did here. > > ::: js/src/vm/Debugger.cpp > @@ +3044,5 @@ > > + THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > > + if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) > > + return false; > > + > > + uint32_t id = args[0].toInt32(); > > We should add some jit-tests. Also the fuzzers probably won't like the > unchecked toInt32() here :) I left it there, since that code is removed in the follow-up patch ;). But I'll definitely add testcases. It is on my list of things to do before landing this all.
Assignee | ||
Comment 13•10 years ago
|
||
Attachment #8503087 -
Attachment is obsolete: true
Attachment #8505451 -
Flags: review?(jdemooij)
Assignee | ||
Comment 14•10 years ago
|
||
Attachment #8505481 -
Flags: review?(benj)
Assignee | ||
Updated•10 years ago
|
Attachment #8504066 -
Attachment is obsolete: true
Assignee | ||
Comment 15•10 years ago
|
||
Comment on attachment 8505451 [details] [diff] [review] Part 1: Dynamically toggle logged ids in Baseline and IonMonkey Review of attachment 8505451 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/vm/Debugger.cpp @@ +3053,5 @@ > + } > + > + args.rval().setBoolean(true); > + if (TraceLogTextIdEnabled(id)) > + return true; These two lines can be removed. ::: js/src/vm/TraceLogging.cpp @@ +584,5 @@ > > +void > +TraceLoggerThreadState::enableTextId(JSContext *cx, uint32_t textId) > +{ > + MOZ_ASSERT(TLTextIdIsToggable(textId)); Add the following here: if (enabledTextIds[textId])) return; @@ +603,5 @@ > +} > +void > +TraceLoggerThreadState::disableTextId(JSContext *cx, uint32_t textId) > +{ > + MOZ_ASSERT(TLTextIdIsToggable(textId)); Add the following here: if (!enabledTextIds[textId])) return;
Assignee | ||
Comment 16•10 years ago
|
||
Comment on attachment 8505481 [details] [diff] [review] Part 2: add setupTraceLogger Review of attachment 8505481 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/vm/Debugger.cpp @@ +3094,5 @@ > + MOZ_ASSERT(textIds.length() == values.length()); > + > + for (size_t i = 0; i < textIds.length(); i++) { > + if (TraceLogTextIdEnabled(textIds[i]) == values[i]) > + continue; These two lines can get removed.
Comment 17•10 years ago
|
||
Comment on attachment 8505481 [details] [diff] [review] Part 2: add setupTraceLogger Review of attachment 8505481 [details] [diff] [review]: ----------------------------------------------------------------- Looks fine, thanks. ::: js/src/vm/Debugger.cpp @@ +3046,4 @@ > return false; > > + RootedValue arg(cx, args[0]); > + RootedObject obj(cx, ToObject(cx, arg)); can you please inline the use of arg? I think it's already been mentioned in the previous review, and unless you have a good argument for keeping it, it would simplify code to delete it, and avoid one useless rooting. RootedObject obj(cx, ToObject(cx, args[0])); @@ +3051,5 @@ > + return false; > + > + AutoIdVector ids(cx); > + if (!GetPropertyKeys(cx, obj, JSITER_OWNONLY, &ids)) > + return false; I know this would be a silly use case of setupTraceLogger, but you could return early here if ids.length() == 0. @@ +3062,5 @@ > + if (!values.reserve(ids.length())) > + return false; > + > + for (size_t i = 0; i < ids.length(); i++) { > + if (!JSID_IS_STRING(ids[i])) { Can this JSID be something else than a string? jsid can be an int32, per the enum, but i wonder if object keys aren't actually all strings. Could you test this, and if they can't anything else, MOZ_ASSERT(JSID_IS_STRING(ids[i])); here instead? @@ +3080,5 @@ > + return true; > + } > + > + RootedValue v(cx); > + if (!JSObject::getGeneric(cx, obj, obj, ids[i], &v)) { Shouldn't we just return false here? getGeneric seems to return false iff it fails (oom and such). @@ +3090,5 @@ > + values.append(ToBoolean(v)); > + } > + > + MOZ_ASSERT(ids.length() == textIds.length()); > + MOZ_ASSERT(textIds.length() == values.length()); Very sane assertions! @@ +3099,5 @@ > + > + if (values[i]) > + TraceLogEnableTextId(cx, textIds[i]); > + else > + TraceLogDisableTextId(cx, textIds[i]); This calls for TraceLogSetEnabledTextId(JSContext*, uint32_t textId, bool enabled), but that's fine to do it this way now. ::: js/src/vm/TraceLoggingTypes.cpp @@ +10,5 @@ > + > +uint32_t > +TLStringToTextId(JSLinearString *str) > +{ > +#define NAME(textId) if (js::StringEqualsAscii (str, #textId)) return TraceLogger_ ## textId; nit: space after StringEqualsAscii isn't needed ::: js/src/vm/TraceLoggingTypes.h @@ +7,5 @@ > #ifndef TraceLoggingTypes_h > #define TraceLoggingTypes_h > > #include "jsalloc.h" > +#include "jsstr.h" can you just declare JSLinearString here, rather than importing the entire header? class JSLinearString;
Attachment #8505481 -
Flags: review?(benj) → review+
Assignee | ||
Comment 18•10 years ago
|
||
(In reply to Benjamin Bouvier [:bbouvier] from comment #17) > @@ +3062,5 @@ > > + if (!values.reserve(ids.length())) > > + return false; > > + > > + for (size_t i = 0; i < ids.length(); i++) { > > + if (!JSID_IS_STRING(ids[i])) { > > Can this JSID be something else than a string? jsid can be an int32, per the > enum, but i wonder if object keys aren't actually all strings. Could you > test this, and if they can't anything else, > MOZ_ASSERT(JSID_IS_STRING(ids[i])); here instead? setupTraceLogger({ 0: true }); Will give a int32 instead of a string ;)
Comment 19•10 years ago
|
||
Comment on attachment 8505451 [details] [diff] [review] Part 1: Dynamically toggle logged ids in Baseline and IonMonkey Review of attachment 8505451 [details] [diff] [review]: ----------------------------------------------------------------- Sorry for the delay! r=me with nits addressed. ::: js/src/jit/BaselineJIT.cpp @@ +859,5 @@ > + if (enable && !engineEnabled) { > + Assembler::ToggleToCmp(enter); > + Assembler::ToggleToCmp(exit); > + } > + if (!enable && !engineEnabled) { Maybe: if (!engineEnabled) { if (enable) { ... } else { ... } } To make it a bit easier to see we're doing nothing if engineEnabled? @@ +880,5 @@ > + > + // Enable/Disable the traceLogger prologue and epilogue. > + CodeLocationLabel enter(method_, CodeOffsetLabel(traceLoggerEnterToggleOffset_)); > + CodeLocationLabel exit(method_, CodeOffsetLabel(traceLoggerExitToggleOffset_)); > + if (enable && !scriptsEnabled) { Same here. ::: js/src/vm/Debugger.cpp @@ +3044,5 @@ > + THIS_DEBUGGER(cx, argc, vp, "enableTraceItem", args, dbg); > + if (!args.requireAtLeast(cx, "Debugger.enableTraceItem", 1)) > + return false; > + > + uint32_t id = args[0].toInt32(); Needs an isInt32() check, but you said that's in another patch?
Attachment #8505451 -
Flags: review?(jdemooij) → review+
Assignee | ||
Comment 20•10 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/c54bb9df733b https://hg.mozilla.org/integration/mozilla-inbound/rev/8db5d425405f
https://hg.mozilla.org/mozilla-central/rev/8db5d425405f https://hg.mozilla.org/mozilla-central/rev/c54bb9df733b
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla36
https://hg.mozilla.org/mozilla-central/rev/aa41463b912e https://hg.mozilla.org/mozilla-central/rev/dd75dcb78dc7
Comment 23•9 years ago
|
||
Yes, Debugger.prototype is probably the best place to put such methods. I see that the functions are conditional on JS_TRACE_LOGGING. Is that enabled in releases? If so, it should be documented.
Flags: needinfo?(jimb) → needinfo?(hv1989)
Assignee | ||
Comment 24•9 years ago
|
||
Correct, JS_TRACE_LOGGING is enabled in release. Opened bug 1118687 for this.
Flags: needinfo?(hv1989)
You need to log in
before you can comment on or make changes to this bug.
Description
•