Open Bug 1006102 Opened 10 years ago Updated 2 years ago

Log error messages from add-on scripts to the add-on console

Categories

(DevTools :: Debugger, defect, P3)

defect

Tracking

(Not tracked)

People

(Reporter: mossop, Unassigned)

References

(Blocks 2 open bugs)

Details

Attachments

(1 file, 14 obsolete files)

47 bytes, text/x-phabricator-request
Details | Review
The current add-on console only logs console.* messages but nsIScriptErrors dispatched by JS error etc. should be caught. It should be a case of creating something similar to ConsoleProgressListener but testing against nsIScriptError.sourceName instead of a window ID.
Summary: Listen for error console messages from add-on scripts and log them to the add-on console → Log error messages from add-on scripts to the add-on console
Assignee: nobody → kmaglione+bmo
Blocks: 1226743
Assignee: kmaglione+bmo → luca.greco
Status: NEW → ASSIGNED
Background:

- What is currently supported by the addon webconsole?

  The addon webconsole currently supports only console API message logging
  (and do not support PageErrors)

- How the addon's console API messages are recognized by the addon webconsole?

  The addon webconsole initializes the ConsoleAPIListener helper with a
  consoleID which is used to filter the messages that are generated by the
  addon's console object

- Where the addon-sdk defines which is the consoleID assigned to the addon's console object?

  The consoleID is assigned to the console object when it is instantiated in the XPIProvider:
  https://dxr.mozilla.org/mozilla-central/rev/d7a0ad85d9fb77916f9d77d62697b852f3dc63e6/toolkit/mozapps/extensions/internal/XPIProvider.jsm#4471

- Why is doesn't work for WebExtension add-ons?

  The console object used in the webextensions contexts (background/tab/popup extension pages 
  and content scripts) is now the Console class defined by "dom/webidl/Console.webidl" and 
  implemented by "dom/base/Console.cpp", which doesn't currently support the consoleID attribute
  on the generated console message events.
Goals of the patches:

- support consoleID on the newly implemented native console API object (and in the 
  addon webconsole, use the consoleID filtering to get the interesting cached messages, 
  as well as the observed ones)

- support consoleID on nsIScriptError as well, to be able to extend the event filtering 
  to the PageErrors counterpart in the addon webconsole

- tag the sandbox object used by WebExtension's content scripts with an addonId, like it is
  currently done for addon-sdk addons in the XPIProvider:
  https://dxr.mozilla.org/mozilla-central/rev/d7a0ad85d9fb77916f9d77d62697b852f3dc63e6/toolkit/mozapps/extensions/internal/XPIProvider.jsm#4453

- add a consoleID to the nsIScriptError generated by AutoJSAPI error reports based on the addonId 
  assigned to the current js global, if any

- get the addonId from the principal's origin attributes or from the sandbox's 
  compartment options, if any

- be able to optionally report an error reported using Cu.reportError on a specific consoleID
  (e.g. by optionally copying the consoleID attribute from the JS object into the nsIScriptError
  created to report the error), needed to report in the addon webconsole errors routed
  or generated by the WebExtensions internals

- support e10s
  - preserve consoleID on console API message events propagated from the child to the main process
    (which are propagated using message managers' messages)
  - preserve consoleID on ScriptErrors events propagated from the child to the the main process
    (which are propagated by the ipc code from "dom/ipc")
I tried to keep the change as simple as possible and it's actually composed by a pretty small number of lines of code, nevertheless this change is composed by changes on many of the platform layers and for this reason I tried to keep the various pieces of the "puzzle" into self-contained small patches (at least as much as possible, but to get the final version of the test case to work they are currently all needed) 

My C++ is a bit rusty, but I tried to stay consistent to the existent code around the changes (my apologies for the mistakes that I've probably done).

The nsIScriptError was particularly tricky and I'm not sure that I've covered all the possible paths that an error can come from, but the two paths covered should be able to catch most of the errors that we'd like to see in the addon webconsole.
Comment on attachment 8703555 [details] [diff] [review]
0001-Bug-1006102-Log-messages-for-background-scripts-shou.patch

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

::: dom/base/Console.cpp
@@ +717,5 @@
> +        if (!poa.mAddonId.IsEmpty()) {
> +          nsAutoCString consoleId;
> +          CopyUTF16toUTF8(poa.mAddonId, consoleId);
> +          consoleId.Insert(NS_LITERAL_CSTRING("addon/"), 0);
> +          CopyUTF8toUTF16(consoleId, mConsoleID);

There's no need to convert back and forth between UTF-8 and UTF-16 here. Something like the following will do:

nsAutoString consoleID;
consoleID.AppendLiteral("addon/");
consoleID.Append(poa.mAddonId);

mConsoleID.Assign(consoleID);
Comment on attachment 8703556 [details] [diff] [review]
0002-Bug-1006102-Log-error-messages-from-add-on-scripts-t.patch

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

::: devtools/shared/webconsole/utils.js
@@ +713,5 @@
>   * @param object aListener
>   *        The listener object must have one method:
>   *        - onConsoleServiceMessage(). This method is invoked with one argument,
>   *        the nsIConsoleMessage, whenever a relevant message is received.
> + * @param string aConsoleID

This should be [aConsoleID]

@@ +714,5 @@
>   *        The listener object must have one method:
>   *        - onConsoleServiceMessage(). This method is invoked with one argument,
>   *        the nsIConsoleMessage, whenever a relevant message is received.
> + * @param string aConsoleID
> + *        Options - The consoleID that this listener should listen to (used in

*Optional

"console ID" should be two words.

@@ +716,5 @@
>   *        the nsIConsoleMessage, whenever a relevant message is received.
> + * @param string aConsoleID
> + *        Options - The consoleID that this listener should listen to (used in
> + *        the addon webconsole to filter log messages and script errors related
> + *        to the consoleID in the form "addon/ID").

Please try to make it clearer which part of this string is a placeholder. E.g., `addon/${ID}`, "addon/<addon-ID>", ...

@@ +721,2 @@
>   */
> +function ConsoleServiceListener(aWindow, aListener, aConsoleID)

`aConsoleID = null`

@@ +785,5 @@
>      }
>  
> +    // If this.consoleID is defined, we're in an addon console and we want to filter
> +    // script errors based on their consoleID.
> +    if (this.consoleID && (aMessage instanceof Ci.nsIScriptError) && aMessage.consoleID !== this.consoleID) {

No need for the parens around the instanceof expression. And it seems to me that if we're filtering on console ID, we should also skip messages that don't have a consoleID property.
Comment on attachment 8703559 [details] [diff] [review]
0004-Bug-1006102-add-consoleID-on-console-api-message-gen.patch

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

::: dom/base/Console.cpp
@@ +785,5 @@
> +  // Customize the consoleID if the current global has an addonId.
> +  if (JSObject* global = JS::CurrentGlobalOrNull(aCx)) {
> +    if (JSAddonId* id = JS::AddonIdOfObject(global)) {
> +      JSString* jss = JS::StringOfAddonId(id);
> +      char* ss = JS_EncodeString(aCx, jss);

This needs to be freed.

Also, this has the same issue as your other instances. There's no need to convert from UTF-16, to UTF-8, and then back to UTF-16 again. Something like the following would do:

nsAutoString consoleId;
AssignJSFlatString(consoleId, JS_ASSERT_STRING_IS_FLAT(JS::StringOfAddonId(id)));
consoleId.Insert("addon/", 0);

mConsoleID.Assign(consoleID);

But it would be better if we could avoid repeating this logic in so many places.
I'm not sure about a lot of this.

I'm worried about the number of places you're having to attach a console ID to messages. It could get complicated to maintain, and it makes me think there are more places we're going to wind up needing it in the future.

Someone who's more familiar with the console API would have better insight than me, though.

Is there some reason we can't use a mechanism more like the one used by the web console, which doesn't seem to need to attach a console ID to messages in so many places?
You should get mrbkap or bholley review for patch against nsIScriptError, they may also be good fit for Console.cpp.

And a devtools peer review. I'm currently looking at these patches.

I think you could get most of stuff working for WebExtensions without modifying any c++.
As far as I know, WebExtensions is mostly made of documents: background pages and popups. Is there any other way to display a WebExt document? Like in a tab? If yes, will it run with Addon principal?
But there is also content script which run in sandboxes.

If you split this into supporting all but content scripts, it will be significantly easier as you should be able to fetch the DOMWindow in ConsoleServiceListener.observe and ConsoleAPIListener.isMessageRelevant. Out of this DOMWindow, you can filter by addonID principal. Instead of passing a consoleID to these, you would directly pass an AddonId and filter by window principal's addon id.
You can get the addon id for a window like this:
  http://mxr.mozilla.org/mozilla-central/source/toolkit/components/extensions/ExtensionManagement.jsm#217

Note also, that I think Mossop had in mind to use this function: mapURIToAddonID
  http://mxr.mozilla.org/mozilla-central/source/toolkit/mozapps/extensions/amIAddonManager.idl#28
It could potentially allow to directly get an AddonId out of a given nsIScriptError.sourceName.
But I don't know if mapURIToAddonID would work for webextension URLs? And if it is efficient enough to be used on all messages?

Regarding content script, It is more complex.
* First because it is sandboxes. So you wouldn't get access to a window. Even if you do, it wouldn't be flagged of the addon id but just the tab principal.
* Second because of e10s. There may be issues in getting everything in the parent process, where lives the Addon actor and various console listeners. But as far as I can tell console.* and error seems to be both forwarded to the parent.

For content script, my suggestion to look for window's principal wouldn't be working. mapURIToAddonID would work. But some of you platform patch may also help. I would be curious to see what platform team think about your patches.
(In reply to Kris Maglione [:kmag] from comment #18)
> Is there some reason we can't use a mechanism more like the one used by the
> web console, which doesn't seem to need to attach a console ID to messages
> in so many places?

Actually the console do filter by something similar. It's not consoleID filter, but nsIScriptError.innerWindowID or Console.innerID (which seems to be the innerWindowID).

I see that Console API defines origin attributes:
  http://mxr.mozilla.org/mozilla-central/source/dom/webidl/Console.webidl#48
May be we can filter by this instead. We do have consoleMessage.originAttributes.addonID.
I would imagine this field is compatible with cross process?
May be we can use that in ConsoleAPIListener, and add similar field to nsIScriptError?
Comment on attachment 8703555 [details] [diff] [review]
0001-Bug-1006102-Log-messages-for-background-scripts-shou.patch

Marking this patch as obsolete (it has been reworked and landed as part of Bug 1211665)
Attachment #8703555 - Attachment is obsolete: true
Attachment #8703556 - Attachment is obsolete: true
Attachment #8703558 - Attachment is obsolete: true
Attachment #8703559 - Attachment is obsolete: true
Attachment #8703560 - Attachment is obsolete: true
Attachment #8703561 - Attachment is obsolete: true
Attachment #8703562 - Attachment is obsolete: true
Attachment #8703563 - Attachment is obsolete: true
Attachment #8703564 - Attachment is obsolete: true
Mark old patches as obsolete.
Comment on attachment 8759703 [details]
Bug 1006102 - Save originAttributes in the Error object.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/57598/diff/1-2/
Comment on attachment 8759704 [details]
Bug 1006102 - Add mochitest-chrome test related to the Error originAttributes property.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/57600/diff/1-2/
Comment on attachment 8759705 [details]
Bug 1006102 - Add support for filtering errors by addonId in webconsole ConsoleServiceListener helper.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/57602/diff/1-2/
I am trying to do some devtools debugger bug triage and I stumbled across this bug --
there's an updated patch series, but no review and no action for 9 months.
What's the status here?
Flags: needinfo?(lgreco)
Attachment #8759703 - Attachment is obsolete: true
Attachment #8759704 - Attachment is obsolete: true
Attachment #8759705 - Attachment is obsolete: true
Hi Tom,
my apologies for the amount of time I needed to get back to this.

This issue is still valid (the errors should be filtered by addon id in the addon debugging toolbox, but they are currently all listed), but the proposed approach that was attached here (which was the same approach of the addon log messages filtering) was too complex and it wasn't able to solve the issue for all the errors that we log for an extension (e.g. the previous approach was able to filter the errors that were raised in the extension code itself, but the errors that we raise from the WebExtensions internals were still be reported with the wrong filename URL, e.g. the chrome URL related to the WebExtensions internals JSM modules, or no filename URL at all, and they will not be visible if not associated to the addon somehow).

I took a fresh look at this issue as part of the ongoing changes related to the oop extensions debugging (Bug 1302702) and I tried a simpler approach that I was thinking of for a while:

- the errors can be filtered based on the error sourceName (which should point to an extension URL of the target extension), the url is coverted into an addonId using the nsIAddonPolicyService and checked against the target addonId
- collect the caller info using Componets.stack.caller in the stub functions that wrapps the injeted APIs, and then use this caller info object to pass the fileName and lineNumber in the Error contructor (so that the schema validation errors and the other errors raised by the WebExtensions API internals are correctly logged and filtered in the addon debugging toolbox

I've closed the previous review request and opened a new one with the new patches that prototype this new approach.

These new patches are based on top of the changes from Bug 1302702 and so I'm adding it to the blockers of this issue now, and I'm going to proceed with asking Kris and Alex a feedback on the proposed approach and related changes applied to the WebExtensions internals and the DevTools actors respectively.
Depends on: 1302702
Flags: needinfo?(lgreco)
Product: Firefox → DevTools

This bug has not been updated in the last 6 months. Resetting the assignee field.
Please, feel free to pick it up again and add a comment outlining your plans for it if you do still intend to work on it.
This is just trying to clean our backlog of bugs and make bugs available for people.

Assignee: lgreco → nobody
Status: ASSIGNED → NEW

Luca: is this still an issue?

Honza

Flags: needinfo?(lgreco)
Attachment #8862028 - Attachment is obsolete: true
Attachment #8862029 - Attachment is obsolete: true

(In reply to Jan Honza Odvarko [:Honza] (always need-info? me) from comment #37)

Luca: is this still an issue?

Yes, the issue should still be there: the error listener (ConsoleServiceListener) doesn't filter the errors yet and so any error logged in the extension process is being collected and logged in the "Addon Debugging"'s devtools console panel.

I was pretty sure that the attached patches were not going to be able to apply cleanly on a recent mozilla-central tip, and so I took a look into updating the patch and add a xpcshell test case to it.

Flags: needinfo?(lgreco)
Severity: normal → S3

The severity field for this bug is relatively low, S3. However, the bug has 5 duplicates.
:bomsy, could you consider increasing the bug severity?

For more information, please visit auto_nag documentation.

Flags: needinfo?(hmanilla)

The last needinfo from me was triggered in error by recent activity on the bug. I'm clearing the needinfo since this is a very old bug and I don't know if it's still relevant.

Flags: needinfo?(hmanilla)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: