Correct way to log from a WEE for both developer and log collection usage

[gregglind]

Osmose,

What is the Right Way to log from a webExtension, both for local usefulness, and for error collection?
What's the RIght Way to control the logging level? React to a pref?

[Osmose]

Inside normal webextension code? Just use console.log, console.error, etc. Or, if suitable, throw an error and don't catch it.

Inside privileged code, you'll want to use Log.jsm. It has a useful method manageLevelFromPref that handles the pref magic for you. Here's an example of setting a logger up: https://searchfox.org/mozilla-central/source/browser/modules/BrowserErrorReporter.jsm#146

@mythmon also discovered recently some specifics about logging errors with Log.jsm vs calling Cu.reportError, but I don't remember the nuance of his findings. He can elaborate.

[mythmon]

What I discovered is that Log.jsm's log.error will call Cu.reportError with whatever you pass it. So a line like

try {
  f = new Frob();
} catch (e) {
  log.error("the frob didn't work");
  Cu.reportError(e);
}

results in two errors that get sent to sentry. Further, the error reported from log.error doesn't include a useful traceback. It points to the line where the log happened, not the line where the error happened. Overall, I've stopped using log.error, and am using Cu.reportError directly now. The pattern I'm using is:

1. If you can, just let errors throw. This is the simplest and provides good error messages in Sentry.
2. If you can't let errors throw, catch them, handle them, and then Cu.reportError with the thrown exception. This still provides good error messages in Sentry.
3. If you don't have an exception but still want to report an error, don't use Log.jsm since it doesn't provide good tracebacks in Sentry. Instead use something like Cu.reportError(new Error("Something went wrong")). This will at least include an accurate traceback in Sentry, but won't necessarily point to where the problem occurred.

An open question for me is how to add extra information to an error that you have caught and want to report. I've tried modifying the error message before reporting like this:

try {
  // ...
} catch (e) {
  e.message = "Extra information: " + e.message;
  Cu.reportError(e);
}

This seems to work sometimes, but other times the error message is immutable, and so this pattern itself throws an error. I don't have a good solution for this case.

[biancadanforth]

Thanks osmose and mythmon for the thoughts. Maybe we could use a combination of Log.jsm and Cu.reportError depending on our intention with the logging...

Thinking about how we might be able to toggle console logging for both privileged AND unprivileged code with a single flag/pref... I see two possible options:

1. If we have an experimental API that exposes a Logger say from Log.jsm via a log method, I could use something like study.log("Thing to log")
2. If we simply have a wrapper around console.log that checks for a flag or pref in the WE/unprivileged portion of the code:

log(message) {
  if (this.shouldLog) {
    console.log(message);
  }
}

[gregglind]

Went with pref-controlled subclassed console in #178. Will consider further logging revisions. Api isn't clear for what browser.study.logger should be / do.

[motin]

gregglind commented in #210 (comment):

This needs an issues to discuss. I dropped it originally because of these issues:

1. 5 arguments feels arbitrary.
2. How do you control what level this logging is at?
3. None of this feels idiomatic.

Counter suggestion:

• browser.log.{info,log} whatever api.

Console.log is how we are supposed to log, but it all feels very unresolved.

[motin]

The goal is to provide a way for web extension developers to log messages which are hidden by default but can be displayed via a preference. This way we can ship add-ons with logging enabled but hidden, which simplifies testing and debugging without polluting the browser console by default.

1. 5 arguments feels arbitrary.

Agree. Just didn't find how to define arbitrary amount of arguments in the schema - checked https://firefox-source-docs.mozilla.org/toolkit/components/extensions/webextensions/schema.html#api-schemas
@aswan, help wanted.

2. How do you control what level this logging is at?
3. None of this feels idiomatic.
   Counter suggestion:

• browser.log.{info,log} whatever api.

To have info, log, debug, warn etc is much clearer.

browser.log itself seems like a way to send messages to the browser console.

Counter-counter suggestion:

• browser.addonLog.{info,log,debug,warn,error} - This implies that the log messages would be prefixed with the addon id/widgetId, and the preference to control the log-level would be extensions.${widgetId}.logLevel

Console.log is how we are supposed to log, but it all feels very unresolved.

Can we create our own console.log instances without privileged code? If so, that is of course a better approach.