Closed Bug 944701 Opened 6 years ago Closed 6 years ago

Tracelogger: make it possible to toggle when tracelogger is enabled


(Core :: JavaScript Engine, defect)

Not set





(Reporter: h4writer, Assigned: h4writer)




(1 file, 1 obsolete file)

The concept here is to being able to call a JS function to enable when logging may start. It will automatically stop when it goes out of scope. So it will only be able to log the function it is enabled on and all calls in there. It automatically stops when that function stops.

This doesn't remove hooks or anything. So all scripts will still call the logger functions, only tracelogger will ignore them when disabled.

(So disabling the tracelogger will in this case still have the small overhead. The hooks are not removed out of Ion code).
Depends on: 944392
I think it would be better to be able to mark functions as triggering logging. I.e., something like `traceLogFunction(myFunction)`. This would start tracelogging as soon as `myFunction` enters the stack, and would stop it once `myFunction` finishes. (Well, in reality it'd probably have to increase/decrease a counter and start/stop logging when changing from/to 0.)
Attached patch start/stop logging! (obsolete) — Splinter Review
This is how the startup will get filtered out of the tl-beta site!

1) Adds two functions startTraceLogger & stopTraceLogger to the js-shell. If you can pinpoint how to add them in the browser, be my guest.

2) Adds TLOPTIONS, which has DisableOffThread and DisableMainThread. These options disables automatic logging of the main thread or the off thread. The first one is needed to enable it through scripting. (The second is only to filter all offthreads and only show mainthread anymore)

So it is now possible to log only a particular script by doing:

TLOptions=DisableMainThread js script.js

with script.js:
function test() {

It handles out-of sync start/stop calls gracefully. So it does not stop at the end of a function automatically. So differently than discussed. It just starts logging upon start and keeps a counter how many times start is called. When that count is 0 again, we stop logging. In order to support recursive calls...

I could add a RAII autoTraceLogger(). Adding a function "traceLogFunction(myFunction)" will need bug 944698 to finish first.
Assignee: nobody → hv1989
Attachment #8405921 - Flags: review?(till)
Comment on attachment 8405921 [details] [diff] [review]
start/stop logging!

Review of attachment 8405921 [details] [diff] [review]:

Hmm, I'm not sure I think this is entirely the right approach.

IIUC, you're still always pushing all events, but set them to disabled, right? And you do that to always have a valid and balanced state of the entire stack, in the face of events that finish out-of-order?

Why doesn't it work to do roughly the following:
- in startEvent, check if the logger is enabled, do nothing if not
- in stopEvent, check if the event is on the top of the stack. If so, stop it. If not, do nothing

Additionally, you could replace the loggers by do-nothing versions if the stack is empty. That way, the overhead should be very low, and we might finally get away with enabling the TL infrastructure unconditionally. (In another bug, obviously.)

And finally, it'd be nice to always only start logging after the self-hosting stuff has been initialized. Maybe add something like `InitializeTraceLogging`, which has to be called before any of the other functions do anything? Then that could be called after `InitSelfHosting`.

Review comments on the current code below:

General nit: s/JS_ASSERT/MOZ_ASSERT/

I mentioned this inline, too: I think it makes sense to encapsulate the members of StackEntry. Looking over the code again, the same is true, and even more warranted, for TreeEntry. Exposing members of structs inside unions is pretty fragile.

::: js/src/vm/TraceLogging.cpp
@@ +216,5 @@
> +        if (!traceLoggers.isTextIdEnabled(stack[i].s.textId))
> +            continue;
> +#ifdef DEBUG
> +        TreeEntry entry;
> +        if (!getTreeEntry(parent->treeId, &entry))

Doesn't it make more sense to assert here?

@@ +258,5 @@
> +
> +    return true;
> +}
> +
> +bool

This rval seems to indicate two different things: successful execution of the function, but with the result of not disabling the logger, and failure to stop logging in a controlled way. Given that you're not checking the result anywhere, maybe only use it to signal the failure, and return true in the other case?

@@ +705,1 @@
>  #endif

Either adapt these asserts, or remove the entire DEBUG block

::: js/src/vm/TraceLogging.h
@@ +188,5 @@
>          data()[next_++] = data;
>      }
>      T &pushUninitialized() {
> +        MOZ_ASSERT(next_ < capacity_);

Good catch

@@ +294,5 @@
>          uint32_t lastChildId;
> +        struct {
> +            uint32_t textId: 31;
> +            uint32_t active: 1;
> +        } s;

Good idea. I wonder if it'd make sense to steal some bits for treeId, too. Or do you expect to have too many trees for that to make sense? I can't see how that'd be the case.

If you do that (but maybe even if not), I think it makes sense to add accessors for these members, so they don't have to be addressed via

@@ +410,5 @@
>      bool initialized;
>      bool enabled;
>      bool enabledTextIds[TraceLogger::LAST];
> +    bool disableMainThread;
> +    bool disableOffThread;

As always, I'm not a fan of `disableFoo`. I get that this symmetric with the env arg options, but I still think these should be `{main|off}ThreadEnabled}`, and be initialized to true, with TL_OPTIONS setting them to false if required. (In any case, the wording should be switched around: they describe a state, not an activity.)
Attachment #8405921 - Flags: review?(till)
Addresses review comments. (We decided it might be good to do a follow-up which would iterate the JS stack during enable. So we don't need to keep the stack in sync when tracelogger is disabled)
Attachment #8405921 - Attachment is obsolete: true
Attachment #8406864 - Flags: review?(till)
Comment on attachment 8406864 [details] [diff] [review]
start/stop logging!

Review of attachment 8406864 [details] [diff] [review]:

Nice, thanks. r=me with one nit addressed:

The convention is to only use a "get" prefix on fallible getters, not on infallible ones like all the StackEntry getters. Example from the top of my head: JSFunction::nonLazyScript() vs JSFunction::getOrCreateScript(). In short: please rename all the getters to get rid of the "get" prefix, and add a "_" postfix to the fields where they'd collide.

(Also, yay for interdiff working on this patch!)
Attachment #8406864 - Flags: review?(till) → review+
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla31
You need to log in before you can comment on or make changes to this bug.