Different falsy values being incorrectly set as repeated messages in console.log()

RESOLVED FIXED in Firefox 47

Status

RESOLVED FIXED
3 years ago
9 months ago

People

(Reporter: alice0775, Assigned: nchevobbe, Mentored)

Tracking

(Blocks: 1 bug, {regression})

31 Branch
Firefox 47
regression
Dependency tree / graph

Firefox Tracking Flags

(firefox47 fixed)

Details

(Whiteboard: [polish-backlog])

Attachments

(1 attachment)

(Reporter)

Description

3 years ago
This is regrssion since Firefox31.


Steps To Reproduce:
1. Open Web Console (Ctrl+Shift+K)
2. Clear log and then Copy following and paste to eval

function log(x){console.log(x)}
log(undefined)
log(Infinity)
log(NaN)
   ---- undefined     3

3. Clear log and then Copy following and paste to eval

function log(x){console.log(x)}
log(Infinity)
log(undefined)
log(NaN)
   ---- Infinity     3

3. Clear log and then Copy following and paste to eval

function log(x){console.log(x)}
log(NaN)
log(Infinity)
log(undefined)
   ---- NaN         3

Actual results:

Logs are aggregated in one.、 and output value is the first one.

Expected Results:
Log should not be aggregated together.  Output value must be different.
(Reporter)

Comment 1

3 years ago
Regression window:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=b747c35ac54b&tochange=b8b7b62bc9e9

Suspect: 1c12ded4cd82	Mihai Sucan — Bug 920116 - Show full stack traces for console logged messages; r=robcee
Blocks: 920116
Blocks: 1111089
Summary: Not consistent output from console.log() → Different falsy values being incorrectly set as repeated messages in console.log()
Whiteboard: [polish-backlog]
(Assignee)

Comment 2

3 years ago
Hi, I'd be happy to work on this bug. 
Can someone assign it to me please ? 

Thank you
(In reply to Nicolas Chevobbe from comment #2)
> Hi, I'd be happy to work on this bug. 
> Can someone assign it to me please ? 
> 
> Thank you

Hi Nicolas.  Sure, let's give it a try!  The 'repeating' logic is handled here: https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/console-output.js (look for the string 'repeatID' in that file).  I'm not sure exactly where the bug lies in that file but it might be falsly counting these values as equal.  Let me know if you run into issues.

Also, there's an existing test case here which could be extended with this test case: https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/test/browser_repeated_messages_accuracy.js (which loads this page: https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/test/test-repeated-messages.html).
Assignee: nobody → chevobbe.nicolas
Mentor: bgrinstead
Status: NEW → ASSIGNED
(Assignee)

Comment 4

3 years ago
Hi there.
I investigated a little an I think this patch resolve the issue.

In https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/webconsole.js#2183 , the _outputMessageFromQueue function tells if a message should be repeated by calling the _filterRepeatedMessage function
> let isRepeated = this._filterRepeatedMessage(node);

So I took a look at filterRepeatedMessage :
> let uid = repeatNode._uid;
> let dupeNode = null;
> [...]
>   let lastRepeatNode = lastMessage.getElementsByClassName("message-repeats")[0];
>   if (lastRepeatNode && lastRepeatNode._uid == uid) {
>     dupeNode = lastMessage;
>   }

A message should be repeated if it has the same _uid attribute than the last message.
The _uid attribute is declared in https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/console-output.js , in _renderRepeatNode , which only JSON.stringify this.repeatID .

If we look at the Messages.Extended constructor, we can see this line :
>  this._repeatID.messagePieces = this._repeatID.messagePieces = messagePieces + "";

In the case of falsy values, messagePieces is an object 
> {
>   type: undefined|null|NaN
> }

And thus the messagePieces + "" returns "[Object object]", whether the type is null, undefined or NaN. 
And that's what causes the message to be repeated.

So, instead of concatenating, if we stringify messagePieces, we don't have the repeated values anymore
> -  this._repeatID.messagePieces = messagePieces + "";
> +  this._repeatID.messagePieces = JSON.stringify(messagePieces);

As you suggested, I added some tests to https://dxr.mozilla.org/mozilla-central/source/devtools/client/webconsole/test/browser_repeated_messages_accuracy.js in order to test this bug.

Then i ran :
> /mach test devtools/client/webconsole/*

And everything passed ( except one TODO ).

Let me know if something is wrong, or if I can push this patch to TRY.

Thank you
Attachment #8714098 - Flags: review?(bgrinstead)
(Assignee)

Comment 6

3 years ago
Thanks for pushing this to TRY. 
The job is now over and there are a few failures in Linux Debug and Windows Debug but I don't really know if it is due to my patch.
(In reply to Nicolas Chevobbe from comment #6)
> Thanks for pushing this to TRY. 
> The job is now over and there are a few failures in Linux Debug and Windows
> Debug but I don't really know if it is due to my patch.

None of those failures look related, so it's looking good.  I'll review the patch today
Comment on attachment 8714098 [details] [diff] [review]
Bug_1218089_v_01.patch

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

This looks good to me, thanks!
Attachment #8714098 - Flags: review?(bgrinstead) → review+

Comment 10

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/1b290ea60421
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox47: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 47
I have reproduced this bug with Firefox nightly 44.0a1(build Id:20151024030248)on
windows 7(64 bit)

I have verified this bug as fixed with Firefox aurora 47.0a2(build Id:20160415004038)
User Agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:47.0) Gecko/20100101 Firefox/47.0

Updated

9 months ago
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.