console.table data is affected by later alterations

ASSIGNED
Assigned to

Status

P3
normal
ASSIGNED
2 years ago
a month ago

People

(Reporter: dxcqcv, Assigned: savvysiddharth)

Tracking

50 Branch

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(5 attachments)

(Reporter)

Description

2 years ago
Created attachment 8822394 [details]
fx-consoleTable-bug.png

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:50.0) Gecko/20100101 Firefox/50.0
Build ID: 20161130210124

Steps to reproduce:

Sort a array like

const inventors =[ 
{ first: 'Albert', last: 'Einstein', year: 1879, passed: 1955 },
{ first: 'Isaac', last: 'Newton', year: 1643, passed: 1727 },
{ first: 'Galileo', last: 'Galilei', year: 1564, passed: 1642 },
{ first: 'Marie', last: 'Curie', year: 1867, passed: 1934 },
{ first: 'Johannes', last: 'Kepler', year: 1571, passed: 1630 },
{ first: 'Nicolaus', last: 'Copernicus', year: 1473, passed: 1543 },
{ first: 'Max', last: 'Planck', year: 1858, passed: 1947 },
{ first: 'Katherine', last: 'Blodgett', year: 1898, passed: 1979 },
{ first: 'Ada', last: 'Lovelace', year: 1815, passed: 1852 },
{ first: 'Sarah E.', last: 'Goode', year: 1855, passed: 1905 },
{ first: 'Lise', last: 'Meitner', year: 1878, passed: 1968 },
{ first: 'Hanna', last: 'Hammarström', year: 1829, passed: 1909 }
                 ];

                 const ordered = inventors.sort((a,b)=>a.year>b.year ? 1: -1);
                 console.table(ordered)


Actual results:

Only display old order


Expected results:

Show new order
(Reporter)

Comment 1

2 years ago
Created attachment 8822396 [details]
fx-consoleTable-bug01.png

Comment 2

2 years ago
Created attachment 8822474 [details]
1326182.html

Comment 3

2 years ago
Created attachment 8822475 [details]
screenshotFF50win7.jpg

WFM with FF50 on Win 7, the table is displayed sorted by "year"

Updated

2 years ago
Component: Untriaged → Developer Tools: Console

Updated

2 years ago
Duplicate of this bug: 1326256
(Reporter)

Comment 5

2 years ago
I think it's console.table bug so did not check other first.
I don't understand what the bug is here.
When I try the attached test, I get the results I expect: a table sorted by year.
Can you say what is wrong?  Otherwise I think we should simply close this.
Flags: needinfo?(dxcqcv)

Comment 7

2 years ago
I'm experiencing this bug as well, but it requires different code. This example is from a JS exercise series, and the original starter file has a second `.sort()` function in the same file that seems to cause the issue.

See below. Even though the `console.table()` function is used on the `firstSort`, in FF it displays the `secondSort`. I'm using v52.0.1.

```
const inventors =[
  { first: 'Albert', last: 'Einstein', year: 1879, passed: 1955 },
  { first: 'Isaac', last: 'Newton', year: 1643, passed: 1727 },
  { first: 'Galileo', last: 'Galilei', year: 1564, passed: 1642 },
  { first: 'Marie', last: 'Curie', year: 1867, passed: 1934 },
  { first: 'Johannes', last: 'Kepler', year: 1571, passed: 1630 },
  { first: 'Nicolaus', last: 'Copernicus', year: 1473, passed: 1543 },
  { first: 'Max', last: 'Planck', year: 1858, passed: 1947 },
  { first: 'Katherine', last: 'Blodgett', year: 1898, passed: 1979 },
  { first: 'Ada', last: 'Lovelace', year: 1815, passed: 1852 },
  { first: 'Sarah E.', last: 'Goode', year: 1855, passed: 1905 },
  { first: 'Lise', last: 'Meitner', year: 1878, passed: 1968 },
  { first: 'Hanna', last: 'Hammarström', year: 1829, passed: 1909 }
];

// Sorts inventors by birth year.
const firstSort = inventors.sort((a, b) => a.year > b.year ? 1 : -1);

console.table(firstSort);

// Sorts the inventors by years lived
const secondSort = inventors.sort(
  (a, b) => {
    return (a.passed - a.year) > (b.passed - b.year) ? -1 : 1;
  }
);
```
Ok, thanks.

My theory for what is going on here is that the table is not rendered -- and in particular the
table elements are not gathered -- until after the entire pasted code has completed.
And, because |sort| sorts in-place, firstSort and secondSort are identical, so the
display is unexpected.

I think there's another bug open about this sort of problem with console.log.

Clearing the needinfo because I think I understand the bug now.
Flags: needinfo?(dxcqcv)
Steps to reproduce:
1. Open the console
2. Evaluate : 
```
x = [1,2,3];
console.table(x);
x.push(4);
console.table(x);
```


Expected results:

I should see 2 tables, one with 3 elements, one with 4 elements

Actual results:

The 2 tables are the same, and contains 4 elements (first console.table is erroneous)

---

This does not happen with console.log
Priority: -- → P3
Summary: Display wrong order after use two sorted function in console.table → console.table data is affected by later alterations

Updated

6 months ago
Product: Firefox → DevTools
(Assignee)

Updated

3 months ago
Duplicate of this bug: 1492558
(Assignee)

Comment 11

2 months ago
This bug is still present, Can I work on this? Which files should I look for to do so?
Flags: needinfo?(nchevobbe)

Comment 12

2 months ago
Hello Siddharth,

So, console.table is handled in this component: https://searchfox.org/mozilla-central/source/devtools/client/webconsole/components/ConsoleTable.js

At first, we don't have the data we need to display the table [1], so we fetch them [2][3]

Since this is happening asynchronously, `x` is now modified, so retrieving the properties for the first console.table will still return the "final" properties, not the one that were in the object at the time of logging.

One possible fix for that, would be to return from the server, when we handle the console.table, all the properties of the logged object (instead of a preview like we currently do).

Console API calls are handled here [4], so we could make something in [5] to detect if we are dealing with a console.table and try to return all the properties directly.

This could be risky performance wise if we are trying to log a very large array/object, so we need to be careful here.

---

[1] https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/client/webconsole/components/ConsoleTable.js#91,96
[2] https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/client/webconsole/components/ConsoleTable.js#47-48
[3] https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/client/webconsole/actions/messages.js#88-107
[4] https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/server/actors/webconsole.js#1542-1557
[5] https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/server/actors/webconsole.js#1722-1744
Flags: needinfo?(nchevobbe)
(Assignee)

Comment 13

2 months ago
Thanks for info 👍!
Will start working on the fix 🙂.
(Assignee)

Comment 14

2 months ago
(In reply to Nicolas Chevobbe from comment #12) 
> One possible fix for that, would be to return from the server, when we
> handle the console.table, all the properties of the logged object (instead
> of a preview like we currently do).
🤔 didn't get the "preview" part, where are we taking preview of object ?
Flags: needinfo?(nchevobbe)

Comment 15

a month ago
(clearing needinfo as we discussed on Slack)
Flags: needinfo?(nchevobbe)
I'm not sure if preview is culprit or not..

For checking what's happening, I added this if condition to this line...
https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/server/actors/webconsole.js#1736

if(message.level == "table" || message.level == "log") {
  dump("\n\n<---------SERVER DUMP START-------->\n\n");
  
  let seen = [];
  dump(JSON.stringify(message, function(key, val) { //to serialize object
                     if (val != null && typeof val == "object") {
                          if (seen.indexOf(val) >= 0) {
                              return;
                          }
                          seen.push(val);
                      }
                      return val;
                  }));

  dump("\n\n");

  dump(JSON.stringify(result.arguments));
  dump("\n\n<---------SERVER DUMP END---------->\n\n");
}

I did this to simply check state of message and result.arguments ...

And I also modified this... https://searchfox.org/mozilla-central/rev/a7f4d3ba4fbfe3efbde832869f1d672fce7122f6/devtools/client/webconsole/actions/messages.js#88-107
to this...

fetchObjectActorData(enumResponse => {
  const {iterator} = enumResponse;
  iterator.slice(0, iterator.count, sliceResponse => {

    let seen = [];
    console.log("<---------CLIENT LOG START-------->");
    console.log("");
    console.log(JSON.stringify(sliceResponse, function(key, val) { //to serialize object
                   if (val != null && typeof val == "object") {
                        if (seen.indexOf(val) >= 0) {
                            return;
                        }
                        seen.push(val);
                    }
                    return val;
                }));
    console.log("");
    console.log("<---------CLIENT LOG END---------->");

    const {ownProperties} = sliceResponse;
    dispatch(messageTableDataReceive(id, ownProperties));
  });
});

to check state of recieved message..

-------------------------

Then I ran following code...

let x = [11,22,33];
console.table(x);
x.push(44);
console.table(x);

Here's what I got on terminal :-

<---------SERVER DUMP START-------->

{"ID":8589934593,"addonId":"","arguments":[[11,22,33]],"columnNumber":1,"consoleID":"","counter":null,"filename":"debugger eval code","functionName":"","groupName":"","innerID":8589934595,"level":"table","lineNumber":2,"prefix":"","private":false,"timeStamp":1541155241134,"timer":null}

[{"type":"object","actor":"server1.conn1.child1/obj29","class":"Array","extensible":true,"frozen":false,"sealed":false,"ownPropertyLength":4,"preview":{"kind":"ArrayLike","length":3,"items":[11,22,33]}}]

<---------SERVER DUMP END---------->



<---------SERVER DUMP START-------->

{"ID":8589934593,"addonId":"","arguments":[[11,22,33,44]],"columnNumber":1,"consoleID":"","counter":null,"filename":"debugger eval code","functionName":"","groupName":"","innerID":8589934595,"level":"table","lineNumber":4,"prefix":"","private":false,"timeStamp":1541155241142,"timer":null}

[{"type":"object","actor":"server1.conn1.child1/obj30","class":"Array","extensible":true,"frozen":false,"sealed":false,"ownPropertyLength":5,"preview":{"kind":"ArrayLike","length":4,"items":[11,22,33,44]}}]

<---------SERVER DUMP END---------->

console.log: "<---------CLIENT LOG START-------->"
console.log: ""
console.log: "{\"ownProperties\":{\"0\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":11},\"1\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":22},\"2\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":33},\"3\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":44}},\"from\":\"server1.conn1.child1/propertyIterator31\"}"
console.log: ""
console.log: "<---------CLIENT LOG END---------->"
console.log: "<---------CLIENT LOG START-------->"
console.log: ""
console.log: "{\"ownProperties\":{\"0\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":11},\"1\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":22},\"2\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":33},\"3\":{\"configurable\":true,\"enumerable\":true,\"writable\":true,\"value\":44}},\"from\":\"server1.conn1.child1/propertyIterator32\"}"
console.log: ""
console.log: "<---------CLIENT LOG END---------->"


----------------------------------------
Here we can see that message sent by server contains property "preview" which seems to hold correct values for array item (that is [11,22,33] for first call, and [11,22,33,44] for second call) for both of "console.table(x)" call,
But for the response at client side we get latest state for both call.

So my question is,

How come preview of object can be issue here, since all properties are being send with it?

And where exactly this message it recieved?
I looked at variable 'enumResponse' in "message.js" file which isn't like the message sent and I coudn't figure out using Browser Content toolbox debugger, as after sending it goes on continuing other server side stuff.

Why does not this happen with console.log() ?
Flags: needinfo?(nchevobbe)

Comment 17

a month ago
> How come preview of object can be issue here, since all properties are being send with it?

Because you chose a simple array, with 3 (then 4) items in it.
Preview will usually contain the first 10 items of the array, so if you console.table on an object with less than 10 items, we'll have everything send right away.
You can try with the following:

```js
let x = Array.from({length: 20}, (_, i) => i);
console.table(x);
x.push("added later")
console.table(x);
```
Flags: needinfo?(nchevobbe)
> Because you chose a simple array, with 3 (then 4) items in it.
> Preview will usually contain the first 10 items of the array, so if you
> console.table on an object with less than 10 items, we'll have everything
> send right away.

Ok, got it, thanks!
(Assignee)

Updated

a month ago
Status: UNCONFIRMED → NEW
Ever confirmed: true
Created attachment 9023034 [details]
Bug 1326182 - Console table affected by later alteration fixed; r=nchevobbe

all properties of object are send instead of preview to fix this
(Assignee)

Updated

a month ago
Assignee: nobody → savvysiddharth
Status: NEW → ASSIGNED
You need to log in before you can comment on or make changes to this bug.