Closed Bug 1448287 Opened 6 years ago Closed 6 years ago

DevTools new event emitter breaks devtools.dump.emit

Categories

(DevTools :: Framework, enhancement, P2)

enhancement

Tracking

(firefox61 fixed)

RESOLVED FIXED
Firefox 61
Tracking Status
firefox61 --- fixed

People

(Reporter: miker, Assigned: miker)

Details

Attachments

(1 file)

devtools.dump.emit is an invaluable helper when it comes to event discovery. Since the new event emitter has been introduced the output looks like this:

GECKO(55053) | EMITTING: emit(send[object Object]) from emit() -> resource://devtools/shared/event-emitter.js:255

Which gives no useful information.

The output should look like this:

GECKO(55053) | EMITTING: stores-update([object Object]) from devtools/server/actors/storage.js:2856

This shows that stores-update was emitted by the storage front and that an object was sent, which indicates that the test can do the following to wait for this event:

let data = await front.once("stores-update");
Has Regression Range: --- → no
Has STR: --- → yes
Priority: -- → P2
Summary: DevTools new event emiter breaks devtools.dump.emit → DevTools new event emitter breaks devtools.dump.emit
This now gives better output that it has given in the past. Most notably, the path now points to the location of the emit call and params (previously [object Object]) are expanded a little and truncated.
Comment on attachment 8961813 [details]
Bug 1448287 - Fix devtools.dump.emit when using new event emitter

https://reviewboard.mozilla.org/r/230628/#review236546

Thanks for the patch Mike, I'd like to see a new version that relies on describeNthCaller, the current approach doesn't always print useful logs.

::: devtools/shared/event-emitter.js:14
(Diff revision 3)
>  
>  const eventListeners = Symbol("EventEmitter/listeners");
>  const onceOriginalListener = Symbol("EventEmitter/once-original-listener");
>  const handler = Symbol("EventEmitter/event-handler");
>  
> +loader.lazyRequireGetter(this, "components", "chrome", true);

Is this used somewhere?

::: devtools/shared/event-emitter.js:293
(Diff revision 3)
> +      typeof target === "number") {
> +    return truncate(target, MAXLEN);
> +  }
> +
> +  // HTML Node
> +  if (target.nodeName) {

Will crash if target is null

::: devtools/shared/event-emitter.js:317
(Diff revision 3)
> +  if (typeof target === "function") {
> +    return `function ${target.name ? target.name : "anonymous"}()`;
> +  }
> +
> +  // Window
> +  if (target.constructor.name === "Window") {

this will fail on emitter.emit("my-event", {constructor: null}), we should add a guard.

::: devtools/shared/event-emitter.js:364
(Diff revision 3)
>      // Object is dead so the toolbox is most likely shutting down,
>      // do nothing.
>    }
>  
> -  dump(`EMITTING: emit(${type}${argsOut}) from ${description}\n`);
> +  let path = getFirstExternalPath();
> +  dump(`EMITTING: ${type}${argsOut} from ${path}\n`);

I find the new output quite confusing:

  EMITTING: thing(happened, ignored) from g
  
To me this looks like "thing" is a function which was called with "happened" and "ignored" as argument, while "thing" is the type of the event.

::: devtools/shared/event-emitter.js:367
(Diff revision 3)
>  
> -  dump(`EMITTING: emit(${type}${argsOut}) from ${description}\n`);
> +  let path = getFirstExternalPath();
> +  dump(`EMITTING: ${type}${argsOut} from ${path}\n`);
> +}
> +
> +function getFirstExternalPath() {

This looks similar to describeNthCaller, can we modify the existing helper to suit our needs?

I see two things here:
- filter out entries containing a given string (devtools/shared/event-emitter.js
- fallback to an error if components stack is not available.

When testing the patch against test_eventemitter_basic.js, the new code logged 

  EMITTING: a() from g
 
while the current code logs 

  EMITTING: emit(a) from emit() -> resource://devtools/shared/event-emitter.js:255

If I filter out event-emitter things I get 

  EMITTING: emit(a) from testWildcard() -> /Users/jdescottes/Development/hg/fx-team/objdir-frontend.noindex/_tests/xpcshell/devtools/shared/tests/unit/test_eventemitter_basic.js:218

which looks pretty good
Attachment #8961813 - Flags: review?(jdescottes)
Comment on attachment 8961813 [details]
Bug 1448287 - Fix devtools.dump.emit when using new event emitter

https://reviewboard.mozilla.org/r/230628/#review239236

::: devtools/shared/event-emitter.js:364
(Diff revision 3)
>      // Object is dead so the toolbox is most likely shutting down,
>      // do nothing.
>    }
>  
> -  dump(`EMITTING: emit(${type}${argsOut}) from ${description}\n`);
> +  let path = getFirstExternalPath();
> +  dump(`EMITTING: ${type}${argsOut} from ${path}\n`);

Changed to `EMITTING: emit(toolbox-opened, Toolbox) from g`

::: devtools/shared/event-emitter.js:367
(Diff revision 3)
>  
> -  dump(`EMITTING: emit(${type}${argsOut}) from ${description}\n`);
> +  let path = getFirstExternalPath();
> +  dump(`EMITTING: ${type}${argsOut} from ${path}\n`);
> +}
> +
> +function getFirstExternalPath() {

Yup, redesigned function as requested.
Comment on attachment 8961813 [details]
Bug 1448287 - Fix devtools.dump.emit when using new event emitter

https://reviewboard.mozilla.org/r/230628/#review240532

Thanks for the updated patch Mike. Some nits and comments, but doesn't require a new round.

R+ with:
- shim simplified as described
- explanations about the necessity of not using components.stack documented

::: devtools/client/shared/webpack/shims/platform-stack-stub.js:24
(Diff revision 4)
>  
>  /**
> - * Return a description of the Nth caller, suitable for logging.
> + * Return the Nth path from the stack excluding substr.
>   *
> - * @param {Number} n the caller to describe
> - * @return {String} a description of the nth caller.
> + * @param {Number}
> + *        n the Nth path from the stack to describe.

nit : "n" should be on the previous line

::: devtools/client/shared/webpack/shims/platform-stack-stub.js:29
(Diff revision 4)
> - * @return {String} a description of the nth caller.
> + *        n the Nth path from the stack to describe.
> + * @param {String} substr
> + *        A segment of the path that should be excluded.
>   */
> -function describeNthCaller(n) {
> -  if (isWorker) {
> +function getNthPathExcluding(n, substr) {
> +  let stack;

This is ust a shim for launchpad, it's not worth duplicating the implementation. 

We could extract getNthPathExcluding to a dedicated module that doesn't use chrome APIs and directly request this module rather than platform/stack from event-emitter and other spots. But that's more for follow up work. 

For now just update the API to be in sync and do something very simple:

  if (isWorker) {
    return "";
  }

  let stack = new Error().stack.split("\n");
  stack = stack.filter(s => s && !s.contains(filter));
  return stack[n + 1];

::: devtools/shared/event-emitter.js:320
(Diff revision 4)
> +  if (target.constructor &&
> +      target.constructor.name &&
> +      target.constructor.name === "Window") {

nit:
  if (target.constructor && target.constructor.name === "Window")
  
  is enough here.

::: devtools/shared/platform/stack.js:16
(Diff revision 4)
>  
>  /**
> - * Return a description of the Nth caller, suitable for logging.
> + * Return the Nth path from the stack excluding substr.
>   *
> - * @param {Number} n the caller to describe
> - * @return {String} a description of the nth caller.
> + * @param {Number}
> + *        n the Nth path from the stack to describe.

nit: n should be on the previous line

::: devtools/shared/platform/stack.js:23
(Diff revision 4)
> + *        A segment of the path that should be excluded.
>   */
> -function describeNthCaller(n) {
> -  if (isWorker) {
> -    return "";
> +function getNthPathExcluding(n, substr) {
> +  let stack;
> +  try {
> +    throw new Error();

You mentioned in the previous changeset that components.stack was not always available. I assume you don't mean content/launchpad (which is handled by the shim). In which other cases is components.stack unavailable?

Not using it makes us lose the function name from the log, so there should be a good reason and it should probably be documented here with a comment.

::: devtools/shared/platform/stack.js:31
(Diff revision 4)
>    }
>  
> -  let caller = components.stack;
> -  // Do one extra iteration to skip this function.
> -  while (n >= 0) {
> -    --n;
> +  // Remove this method from the stack
> +  stack = stack.splice(1);
> +
> +  stack = stack.map(name => {

"name" sounds very specific for this map() function. We could simply keep a very vague "line"

::: devtools/shared/platform/stack.js:39
(Diff revision 4)
> -  }
> +    }
> +    return name;
> +  });
>  
> -  let func = caller.name;
> -  let file = caller.filename;
> +  if (substr) {
> +    stack = stack.filter(name => {

same comment about the argument name "name"

::: devtools/shared/platform/stack.js:47
(Diff revision 4)
> -  let path = file + ":" + caller.lineNumber;
>  
> -  return func + "() -> " + path;
> +  if (!stack[n]) {
> +    n = 0;
> +  }
> +  return (stack[n] || "") + "\n";

I wouldn't force "\n" here, it's up to the caller to format this as they want.
Attachment #8961813 - Flags: review?(jdescottes) → review+
Comment on attachment 8961813 [details]
Bug 1448287 - Fix devtools.dump.emit when using new event emitter

https://reviewboard.mozilla.org/r/230628/#review240904

::: devtools/client/shared/webpack/shims/platform-stack-stub.js:24
(Diff revision 4)
>  
>  /**
> - * Return a description of the Nth caller, suitable for logging.
> + * Return the Nth path from the stack excluding substr.
>   *
> - * @param {Number} n the caller to describe
> - * @return {String} a description of the nth caller.
> + * @param {Number}
> + *        n the Nth path from the stack to describe.

We use this style in most of our codebase.

::: devtools/shared/event-emitter.js:320
(Diff revision 4)
> +  if (target.constructor &&
> +      target.constructor.name &&
> +      target.constructor.name === "Window") {

In your previous comment you said it would fail on `target = {constructor: null}`

So let's keep it this way.

::: devtools/shared/platform/stack.js:16
(Diff revision 4)
>  
>  /**
> - * Return a description of the Nth caller, suitable for logging.
> + * Return the Nth path from the stack excluding substr.
>   *
> - * @param {Number} n the caller to describe
> - * @return {String} a description of the nth caller.
> + * @param {Number}
> + *        n the Nth path from the stack to describe.

We use this style in most of our codebase.
Comment on attachment 8961813 [details]
Bug 1448287 - Fix devtools.dump.emit when using new event emitter

https://reviewboard.mozilla.org/r/230628/#review240904

> We use this style in most of our codebase.

That's a minor detail but I don't think we do. We use either

@param {Type} paramName
       description

or 

@param {Type} paramName description

but here this is

@param {Type}
       paramName description

> In your previous comment you said it would fail on `target = {constructor: null}`
> 
> So let's keep it this way.

You need if (target.constructor && target.constructor.name === "Window"). Your previous version just had if (target.constructor.name === "Window")
But target.constructor.name is redundant with target.constructor.name === "Window".
Pushed by mratcliffe@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/682edbc61fa6
Fix devtools.dump.emit when using new event emitter r=jdescottes
https://hg.mozilla.org/mozilla-central/rev/682edbc61fa6
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: