Fine tuned logging in devtools code

NEW
Unassigned

Status

enhancement
P3
normal
4 years ago
5 months ago

People

(Reporter: Honza, Unassigned)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment)

Improve logging from within the devtools code base (currently mostly using dump).

Some requirements:
- Simple API
- Scope logging (do not log everything, pick just specific modules/dirs through an UI)
- Search within the log list
- See stack trace for every log (can be an option if slow)
- Clicking on a source link should show the source (open source view or browser debugger UI)
- It would be nice if some logs can be highlighted e.g. by appending "!!!" (no quotes) at the beginning of the log message (or having generic syntax). Very useful.


We probably want to reuse the existing Browser Console UI (if possible)

---

API suggestions:

// Get tracing object for the current module
const Trace = require("devtools/toolkit/shared/trace").getTrace(this);

// Create a log. The object should be explorable through the Variables View
Trace.sysout("a message", anObject);

- We might want to mimic console.* API (e.g. Trace.log) or me different on purpose.

// Create an error log
try {
} catch (err) {
  Trace.error(err);
  Trace.error("There is an error:", err);
}

- We might want to have error logs highlighted in the UI (e.g. displayed in red automatically)

Thoughts?

Honza
Assignee: nobody → odvarko
I think this would be a nice to have for toolkit actually. Fine grained logging is desirable for all sorts of modules, this could also be useful for extensions.
(In reply to Philipp Kewisch [:Fallen] from comment #1)
> I think this would be a nice to have for toolkit actually. Fine grained
> logging is desirable for all sorts of modules
Agree (my example already uses "devtools/toolkit/shared/trace" path already)

> this could also be useful for extensions.
Yep (I am also thinking about this)

Honza
Btw. I did some experiments as part of this patch:
https://bug1168872.bugzilla.mozilla.org/attachment.cgi?id=8615976
(it'll be removed from the patch eventually, but it's already useful!)

It currently needs FBTrace extension to see the nice output:
http://getfirebug.com/releases/fbtrace/3.0/fbtrace-3.0b1.xpi

Bug 1168872 - Support for server side logging 

Honza
Another requirement is that logging should incur near zero overhead in user builds. It's nice to be able to easily dig into errors when debugging, but that shouldn't come at the expense of making the users' everyday tasks slower.
We have been updating Console.jsm lately to hopefully address these needs.  Once Bug 1172141 lands, you can create a console like this:

let {ConsoleAPI} = Cu.import("resource://gre/modules/devtools/Console.jsm", {});
let console = new ConsoleAPI({
  prefix: "My Prefix",
  maxLogLevel: "error",
  maxLogLevelPref: "testing.maxLogLevel",
});

Then you can use the webconsole search on the prefix to filter only the logs coming from this instance.  The only logs that will show up for user builds will be what you specified via maxLogLevel (most likely 'error' or 'none'), and a developer can toggle the maxLogLevelPref to be any of the log levels: https://dxr.mozilla.org/mozilla-central/source/toolkit/devtools/Console.jsm#281.

I'd be very interested to hear if Console.jsm is missing anything you need.
See Also: → 1172141
Console.jsm also already follows the console API, integrates with Browser Console / Browser Toolbox, and dumps to stdout as well as to the UI.  I'd argue for extending this module wherever necessary rather than coming up with something new.
Yep, I like ConsoleAPI and I think we should built our-devtools-tracing on top of it.

Note that there is also support in Add-On SDK:
https://github.com/mozilla/addon-sdk/blob/master/lib/sdk/console/plain-text.js

Implementation supporting hooks:
https://github.com/mozilla/addon-sdk/blob/master/lib/sdk/test/loader.js#L47
We could get an inspiration from this and make sure that whatever we come up with is extensible an extensions can, for instance, forward logs into other places.

Yes, there are missing things, see below.

---

Here is an etherpad where we discussed the API
https://etherpad.mozilla.org/7VUOFQG3gQ
(the config file presented at the bottom could based on the maxLogLevelPref)

An example:
const trace = require("toolkit/shared/trace").getTrace(category);

trace.log("Hello World!");
trace.warn("Hello World!");
trace.error("Hello World!");

// Performance optimization
if (trace.isLogEnabled) {
  let msg = ... // time consuming computation of the trace message
  trace.log(msg);
}

We've planned keeping the tracing API simple (simpler than the console API) and introduce only 3 methods for 3 levels of logging. We can discuss further API additions later as needed (e.g. 4th level represented by trace.debug, etc.)

Except of per-level logging (log|warn|error) we also need per-category logging. Where "category" will mostly correspond to a module (or more modules).

We should be able to say: I want to see logs only from "netmonitor/har" module. In the next step we should also be able to say: I want to see only errors from all modules and everything from "netmonitor/har".

For the per-category logging we need an extra UI that displays a tree of categories (mimicking structure of our modules) allowing the user on/off each (+ perhaps picking a color for logs coming from specific module). Of course, either a single module or entire directory can be checked.
Not yet sure where this UI will be available, but should be part of the existing browser console somehow. Thoughts?

Honza
Flags: needinfo?(jwalker)
Flags: needinfo?(bgrinstead)
> Here is an etherpad where we discussed the API
> https://etherpad.mozilla.org/7VUOFQG3gQ
> (the config file presented at the bottom could based on the maxLogLevelPref)
> 
> An example:
> const trace = require("toolkit/shared/trace").getTrace(category);
> 
> trace.log("Hello World!");
> trace.warn("Hello World!");
> trace.error("Hello World!");
> 
> // Performance optimization
> if (trace.isLogEnabled) {
>   let msg = ... // time consuming computation of the trace message
>   trace.log(msg);
> }
> 
> We've planned keeping the tracing API simple (simpler than the console API)
> and introduce only 3 methods for 3 levels of logging. We can discuss further
> API additions later as needed (e.g. 4th level represented by trace.debug,
> etc.)

The API seems sane.. if the module is just wrapping Console.jsm then it'd be trivial to expose other log levels and logging features (like table, group, trace, etc).

> Except of per-level logging (log|warn|error) we also need per-category
> logging. Where "category" will mostly correspond to a module (or more
> modules).
> 
> We should be able to say: I want to see logs only from "netmonitor/har"
> module. In the next step we should also be able to say: I want to see only
> errors from all modules and everything from "netmonitor/har".
> 
> For the per-category logging we need an extra UI that displays a tree of
> categories (mimicking structure of our modules) allowing the user on/off
> each (+ perhaps picking a color for logs coming from specific module). Of
> course, either a single module or entire directory can be checked.
> Not yet sure where this UI will be available, but should be part of the
> existing browser console somehow. Thoughts?

I think in order to support per-category logging, we'll need to send a message to the webconsole frontend (for the Browser Console) telling it about new categories.  Then the frontend can populate some kind of menu popup tree thing that lets you toggle certain category visibility.  Ideally we could tie this in with the `maxLogLevelPref` feature in Console.jsm so that the state is persisted across reloads.  Let's discuss it further next week.

A follow up could include filtering per-category *and* per-level logging (i.e. only show errors from everything except "netmonitor/har"), but I wouldn't group that into a first round of work as it could get complex.
Flags: needinfo?(bgrinstead)
Flags: needinfo?(jwalker)
(In reply to Brian Grinstead [:bgrins] from comment #8)
> I think in order to support per-category logging, we'll need to send a
> message to the webconsole frontend (for the Browser Console) telling it
> about new categories.  Then the frontend can populate some kind of menu
> popup tree thing that lets you toggle certain category visibility.  Ideally
> we could tie this in with the `maxLogLevelPref` feature in Console.jsm so
> that the state is persisted across reloads.  Let's discuss it further next
> week.
> 
> A follow up could include filtering per-category *and* per-level logging
> (i.e. only show errors from everything except "netmonitor/har"), but I
> wouldn't group that into a first round of work as it could get complex.
Yes, all make sense.

One more thing. I believe that we should also support logging from child
processes. Currently separate (Browser Content) Console needs to
be opened, which makes it hard to see order of logs coming from both
parent and child process (seeing the sequence in one list is quite useful when e.g.
debugging child-parent communication). There could be and option or something
if needed.

Honza
Just attaching a patch with some experiments I did. Not final, mainly archiving the state here.

Honza
I am currently not working on this. Unassigned myself,
so somebody else can pick this up.
Honza
Assignee: odvarko → nobody
Product: Firefox → DevTools
Priority: -- → P3
Type: defect → enhancement
You need to log in before you can comment on or make changes to this bug.