1439963 - console.log and output formatter return promises in different orders cross-browser

Status: RESOLVED FIXED

(DevTools :: Console, defect, P3)

Description

[Jonathon Kereliuk]

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/65.0.3325.51 Safari/537.36

Steps to reproduce:

The following code displays the different behaviours of the output formatter in Chrome and Firefox.

const p = Promise.resolve(1); p.then(v => console.log(v));

Chrome output:

1
Promise {[[PromiseStatus]]: "resolved", [[PromiseValue]]: undefined}

Firefox output:

Promise { <state>: "pending" }
1

Comment 1

[Ciprian Muresan [:cmuresan], Formerly of Ecosystem QA - please needinfo @mcoman for things regarding the team]

I was able to reproduce this issue on the latest Nightly build (Build ID 20180225220119).

It seems that all browsers (that I have tested) behave differently:

Opera:
const p = Promise.resolve(1); p.then(v => console.log(v));
console.js:32 1
Promise {[[PromiseStatus]]: "resolved", [[PromiseValue]]: undefined}

Edge:
const p = Promise.resolve(1); p.then(v => console.log(v));
[object Object]{_a: undefined, _c: Array[0], _d: false, _h: 0, _n: false, _s: 0, _v: undefined}
1
eval code (2) (1,43)

Cliqz:
const p = Promise.resolve(1); p.then(v => console.log(v));
Object { _c: [], _a: undefined, _s: 0, _d: false, _v: undefined, _h: 0, _n: false }
1

Vivaldi:
const p = Promise.resolve(1); p.then(v => console.log(v));
1
Promise {<resolved>: undefined}

Comment 2

[Jason Orendorff [:jorendorff]]

This is a question about the developer console, not the JS engine.

The question is, after running a snippet of REPL code and before printing the result, whether or not we should first allow any pending Promise microtasks to finish. Judging by comment 0 it looks like we currently do not, and Chrome does.

Comment 3

[Nicolas Chevobbe [:nchevobbe]]

Logan, would you have an idea how this could be fixed?

Comment 4

[Logan Smyth [:loganfsmyth]]

Attachment: bug1439963-proposed-fix.diff

The example output seems to show 2 separate issues:

1. The console.log outputs show after the eval result, even though the log would have run before that
2. The eval result shows the value as it was after synchronous execution but before microtask queue flush.

For the first one, I'm assuming that something causes those messages to come in in the wrong order. I'm not really looking into that since I assume you're more familiar with that.

For the second issue, I think the thing to do would be to make the evaluation run in its own task, and then process the result in a task that runs immediately after it, so that the first task will complete and fully drain the microtask queue before the evaluated result object is rendered for console display. I've attached a patch to demonstrate what I mean.

Comment 5

[Nicolas Chevobbe [:nchevobbe]]

Attachment: Bug 1439963 - [devtools] Handle evaluation result in a new task, after the evaluation is done. r=ochameau.

This way we ensure that any microtask created by the evaluated expression are
run, which can impact what we send to the client (e.g. Promise.resolve().then(() => 246)
will show a resolved promise instead of a pending one).
Some stubs and node tests are added to ensure this does fix the issue.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/438a2bae7aef
[devtools] Handle evaluation result in a new task, after the evaluation is done. r=ochameau.

Comment 7

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/438a2bae7aef