787985 - Console API messages are not consistent

Status: RESOLVED FIXED

(DevTools :: Console, defect)

Description

[Mihai Sucan [:msucan]]

The window.console API implementation does not send consistent notification messages for every kind of method. The message.arguments property does not always hold the arguments the page scripts give to the method at call time - see for example console.trace(), time(), etc.

We should cleanup the confusion.

(see bug 768096 comment 23)

Comment 1

[Mihai Sucan [:msucan]]

Attachment: proposed patch

This bug did bite me today while working on getting console.trace() to work with the changes I'm doing for bug 783499. Decided to do a patch for this bug: fix all the confused console event messages.

The idea is each console event message has properties about the console API call - level, window ids, function name, file name, etc, and the |arguments| array. This patch ensures that |arguments| always holds the actual arguments that the page author gave to the console method. Currently ConsoleAPI.js causes a lot of confusion by overriding |arguments| in different ways, for different console methods. This forced us to special-case behavior in the WebConsoleActor and in the frontend.

Looking forward to your review. Thanks!

Comment 2

[Mihai Sucan [:msucan]]

Try push:
https://tbpl.mozilla.org/?tree=Try&rev=91f101f2d099

Comment 3

[Panos Astithas (he/him) [:past] (please ni?)]

In multiple sites (e.g. mozilla.org) I'm getting there errors with this patch:

DBG-SERVER: Error handling incoming packet: TypeError: cyclic object value - LDT_send@chrome://global/content/devtools/dbg-transport.js:207
DSC_onPacket/<@chrome://global/content/devtools/dbg-server.js:677
effort@resource://gre/modules/commonjs/promise/core.js:53
resolveDeferred@resource://gre/modules/commonjs/promise/core.js:125
then@resource://gre/modules/commonjs/promise/core.js:34
then@resource://gre/modules/commonjs/promise/core.js:138
DSC_onPacket@chrome://global/content/devtools/dbg-server.js:678
LDT_send/<.run@chrome://global/content/devtools/dbg-transport.js:212

Comment 4

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 701951 [details] [diff] [review]
proposed patch

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

Much cleaner I agree, but we need to fix the cyclic object error.

::: browser/devtools/webconsole/webconsole.js
@@ +1005,5 @@
> +        objectActors.push(aValue.actor);
> +        let displayStringIsLong = typeof aValue.displayString == "object" &&
> +                                  aValue.displayString.type == "longString";
> +        if (displayStringIsLong) {
> +          objectActors.push(aValue.displayString.actor);

I understand that this is not a new change, but you are throwing away the initial value of the long string. It would be best to retain that and ask for the rest in a subsequent request.

Comment 5

[Mihai Sucan [:msucan]]

Attachment: fixed patch

Patch fixed. I had to add a delete for wrappedJSObject - the property that caused the cyclic reference.

It seems that the debugger transport only shows such errors when debugger.log=true in about:config. I'm making a change in local transport to do Cu.reportError(). Not sure if it's the best way - feel free to suggest changes.

Thank you for the finding. Oddly, the try push was green. We should have a way to catch such obvious failures.

Comment 6

[Mihai Sucan [:msucan]]

(In reply to Panos Astithas [:past] from comment #4)
> Comment on attachment 701951 [details] [diff] [review]
> proposed patch
> 
> Review of attachment 701951 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Much cleaner I agree, but we need to fix the cyclic object error.
> 
> ::: browser/devtools/webconsole/webconsole.js
> @@ +1005,5 @@
> > +        objectActors.push(aValue.actor);
> > +        let displayStringIsLong = typeof aValue.displayString == "object" &&
> > +                                  aValue.displayString.type == "longString";
> > +        if (displayStringIsLong) {
> > +          objectActors.push(aValue.displayString.actor);
> 
> I understand that this is not a new change, but you are throwing away the
> initial value of the long string. It would be best to retain that and ask
> for the rest in a subsequent request.

I'm not sure I follow. How am i throwing away the initial value of the long string? I'm using that, afaik, to display long strings, and later the code does a request for the rest of the string, when the user clicks the ellipsis.

The code you pointed at only keeps track of actor IDs for the purpose of releasing those actors, at a later time - when the output is pruned or cleared.

Comment 7

[Panos Astithas (he/him) [:past] (please ni?)]

Comment on attachment 702211 [details] [diff] [review]
fixed patch

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

You are right about the long actor handling, I misread that part.

::: toolkit/devtools/debugger/dbg-transport.js
@@ +216,5 @@
> +      if (Cu.reportError) {
> +        Cu.reportError(msg);
> +      } else {
> +        dump(msg + "\n");
> +        dumpn("Packet was: " + aPacket);

I'd prefer the two dump()s to be unconditional. I find it tedious to keep opening the error console in order to spot errors in my code.

There are also a few more instances of this pattern throughout this file, if you feel like it. No pressure though :-)

Comment 8

[Mihai Sucan [:msucan]]

Attachment: final patch

Thank you!

Updated dbg-transport.js to do Cu.reportError() in other places as well.

Landed in fx-team:
https://hg.mozilla.org/integration/fx-team/rev/1a39357d5197

Comment 9

[Panos Astithas (he/him) [:past] (please ni?)]

https://hg.mozilla.org/mozilla-central/rev/1a39357d5197