974056 - Add logging of devtools event emitter emit calls

Status: RESOLVED FIXED

(DevTools :: Inspector, defect)

Description

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

It is often very difficult to follow the flow of events in devtools code, especially because of our prolific use of promises.

We should add devtools.dump.emit=false (true only for tests) as this allows us to log extra details to test logs.

e.g.
17:42:28     INFO -  EMITTING: select(webconsole)
17:42:28     INFO -  EMITTING: changed([object XULElement] (tab))
17:42:28     INFO -  EMITTING: webconsole-selected([object Object])
...
17:25:25     INFO -  EMITTING: markuploaded()
17:25:25     INFO -  EMITTING: before-new-node-front([Front for domnode/conn28.domnode37] (BODY), inspector-open)
17:25:25     INFO -  EMITTING: new-node-front([Front for domnode/conn28.domnode37] (BODY), inspector-open)
17:25:25     INFO -  EMITTING: inspector-ready([object Object])
17:25:25     INFO -  EMITTING: toolbox-ready([object Object])
17:25:25     INFO -  TEST-PASS | chrome://mochitests/content/browser/browser/devtools/inspector/test/browser_inspector_bug_699308_iframe_navigation.js | found the iframe element
17:25:25     INFO -  EMITTING: before-new-node-front([Front for domnode/conn28.domnode37] (BODY), test)
17:25:25     INFO -  EMITTING: new-node-front([Front for domnode/conn28.domnode37] (BODY), test)
17:25:25     INFO -  EMITTING: select(inspector)
17:25:25     INFO -  EMITTING: changed([object XULElement] (tab))

...
17:42:30     INFO -  EMITTING: destroyed()
17:42:30     INFO -  EMITTING: toolbox-destroyed(TabTarget:null)

Comment 1

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Patch v1

We should wait for Joe's feedback to see if it is okay to have this on for default when testing.

Comment 2

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Patch v1.01

Removed a \n

Comment 3

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Patch V2

Now no longer logs in tests by default

Comment 4

[Heather Arthur [:harth]]

Comment on attachment 8377895 [details] [diff] [review]
Patch V2

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

"hearth" -> "harth" in commit (:

Worried about the big try/catch:

::: browser/devtools/shared/event-emitter.js
@@ +163,5 @@
> +              dump(")");
> +            }
> +          }
> +        } catch(e) {
> +          // Do nothing

We should avoid a big try/catch if we can. What was the reason for it?

Comment 5

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Addressed comments

(In reply to Heather Arthur [:harth] from comment #4)
> Comment on attachment 8377895 [details] [diff] [review]
> Patch V2
> 
> Review of attachment 8377895 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> "hearth" -> "harth" in commit (:
> 

Sorry, no brain today.

> Worried about the big try/catch:
> 
> ::: browser/devtools/shared/event-emitter.js
> @@ +163,5 @@
> > +              dump(")");
> > +            }
> > +          }
> > +        } catch(e) {
> > +          // Do nothing
> 
> We should avoid a big try/catch if we can. What was the reason for it?

We don't, removed and just generally tidied.

Comment 6

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Added more info to log

Now the logging looks like this:

EMITTING: BC_update/<() -> emit(breadcrumbs-updated, [Front for domnode/conn0.domnode29] (DIV#output)) from resource:///modules/devtools/inspector/breadcrumbs.js:695

Comment 7

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Bug 976679 moves event-emitter to toolkit, so you'll need to rebase if that lands before.

Comment 8

[Heather Arthur [:harth]]

Mike, you told me to hold off on reviewing this. Is it ready now?

Comment 9

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Switched to using components.stack

Yup, this is ready for review.

Comment 10

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: event-emitter-logging-974056.patch

We need the try / catch in order to avoid logging info about dead objects (exception). As this is an option enabled by flipping the devtools.dump.emit pref I think we should be fine.

Comment 11

[Heather Arthur [:harth]]

(In reply to Michael Ratcliffe [:miker] [:mratcliffe] from comment #10)
> Created attachment 8383038 [details] [diff] [review]
> event-emitter-logging-974056.patch
> 
> We need the try / catch in order to avoid logging info about dead objects
> (exception). As this is an option enabled by flipping the devtools.dump.emit
> pref I think we should be fine.

It'd be a good to keep it as small as possible. Can we only wrap the statement that would throw the exception?

Comment 12

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: event-emitter-logging-974056.patch

Any part of the for loop that goes through any passed arguments can throw so that is about the smallest we can make it.

Comment 13

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

https://hg.mozilla.org/integration/fx-team/rev/6a73824daf37

Comment 14

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/6a73824daf37