Closed Bug 1371721 Opened 7 years ago Closed 7 years ago

Create a MESSAGES_ADD action to add batches of messages at once

Categories

(DevTools :: Console, enhancement, P1)

Product:
DevTools
Component:
Console
Type:
enhancement

Tracking

(firefox58 fixed)

Status:
RESOLVED FIXED
Milestone:
Firefox 58
Tracking Flags:
Tracking Status
firefox58 --- fixed

People

(Reporter: bgrins, Assigned: ochameau)

References

(Blocks 1 open bug)

Details

(Whiteboard: [reserve-console-html])

Attachments

(5 files, 1 obsolete file)

Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once
59 bytes, text/x-review-board-request
Details
Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once.
59 bytes, text/x-review-board-request
nchevobbe
: review+
Details
Bug 1371721 - Keep logging repeated messages even when we reached the log-limit.
59 bytes, text/x-review-board-request
nchevobbe
: review+
Details
Bug 1371721 - Wait for redux store events before dispatching network-request-payload-ready and network-message-updated events.
59 bytes, text/x-review-board-request
nchevobbe
: review+
Details
Bug 1371721 - Resolve dispatchMessageAdd promise only when the related message is logged.
59 bytes, text/x-review-board-request
nchevobbe
: review+
Details 
Instead of batching up individual MESSAGE_ADD actions, we could save some time in the reducer if we have a single MESSAGES_ADD action.  For instance, if there are too many messages to display we could skip the ones that will become irrelevant before ever adding them to the store
Assignee: nobody → bgrinstead
Status: NEW → ASSIGNED
Iteration: --- → 55.7 - Jun 12
Flags: qe-verify?
Priority: -- → P1
Iteration: 55.7 - Jun 12 → 56.1 - Jun 26
See Also: → 1368100
Iteration: 56.1 - Jun 26 → 56.2 - Jul 10
Flags: qe-verify? → qe-verify-
Iteration: 56.2 - Jul 10 → 56.3 - Jul 24
Assignee: bgrinstead → nobody
Status: ASSIGNED → NEW
Iteration: 56.3 - Jul 24 → ---
Priority: P1 → P3
Whiteboard: [console-html] → [reserve-console-html]
Priority: P3 → P4
Comment on attachment 8908530 [details]
Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once.

Nicolas, I just rebased bgrins's patch. 
It seems to provide valuable wins to console performances.

We go from:
  https://perfht.ml/2x3nI4G
  37% of overall computation in parent process (13500ms) for batchedMessageAdd/throttledDispatchTimeout
Down to:
  https://perfht.ml/2x3LTjp
  19%(5600ms) for setTimeoutIfNeeded/throttledDispatchTimeout

The STR was open mozilla.slack.com with debugger and console in background and record slack reloading.

But I have no idea what this patch really do and the quality of it.

Do you think this patch is in a reviewable state?
May I help getting it in such state?
Attachment #8908530 - Flags: feedback?(nchevobbe)
Comment on attachment 8908530 [details]
Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once.

https://reviewboard.mozilla.org/r/180182/#review185350

Overall I think the patch is almost ready.
We need to take care of the repeated messages, and add tests to make sure everything works as expected.

::: devtools/client/webconsole/new-console-output/reducers/messages.js:174
(Diff revision 1)
> +          // Once we've added the max number of messages that can be added stop.
> +          // TODO: what about repeats?

This needs to be sorted out
Attachment #8908530 - Flags: feedback?(nchevobbe) → feedback+
Assignee: nobody → poirot.alex
Status: NEW → ASSIGNED
Priority: P4 → P1
Iteration: --- → 57.3 - Sep 19
Comment on attachment 8909343 [details]
Bug 1371721 - Keep logging repeated messages even when we reached the log-limit.

To be honest, I don't know what we should really do. This is just one option.

Also, regarding tests, shouldn't the existing one be enough?
What kind of tests did you had in mind?

I imagine these patches are going to change the behavior of already logged messages, so if most of our tests are only live message, sent one by one, it may be not covered. But I imagine we have some test for the new "persist logs" feature?
Comment on attachment 8908530 [details]
Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once.

I've contributed to this patch batchedRequestUpdates, which is very similar to the two other ones. And also fix various eslint issues.
Comment on attachment 8909401 [details]
Bug 1371721 - Wait for redux store events before dispatching network-request-payload-ready and network-message-updated events.

I've kept that separated from the first patch as I wanted to keep bgrins patch almost as he wrote it and contribute on top of it, like this.

The made a bunch of test fail like here:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=cbbcad269cdfcd7f235050e914a081b7a2381ec5
  https://treeherder.mozilla.org/logviewer.html#?job_id=131768384&repo=try&lineNumber=3039

Hopefully, this new try is going to be full green:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=0ca3be977c672a33491404eaa0fd91cecb920ac0
There is still some failures:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=2f5f440720daa02b59f6cbf67302313eec27a0cf&selectedJob=131802393
Looks like races around dispatchMessageAdd.
jsterm.execute() promise seems to resolve with the wrong evaluation result.
dispatchMessageAdd was resolving arbitrarity, whenever a new-messages event fired.
m.timeStamp was undefined as we were no longer passing it alongside with new-messages
message.timeStamp was also undefined as it is message.timestamp (lowercases)

Hopefully, with all that, try is finally going to be green:
  https://treeherder.mozilla.org/#/jobs?repo=try&revision=f2f1241280ba1cd0fd01ce8dc5fa0cf8f795736e
Comment on attachment 8908530 [details]
Bug 1371721 - Create a MESSAGES_ADD action to add batches of messages at once.

https://reviewboard.mozilla.org/r/180182/#review186464

Please remove the 2 if blocks in `limitTopLevelMessageCount`

::: devtools/client/webconsole/new-console-output/reducers/messages.js:459
(Diff revision 3)
> +    if (mapHasRemovedIdKey(record.messagesObjectPropertiesById)) {
> +      record.set("messagesObjectPropertiesById",
> +        record.messagesObjectPropertiesById.withMutations(cleanUpCollection));
> +    }
> +    if (mapHasRemovedIdKey(record.messagesObjectEntriesById)) {
> +      record.set("messagesObjectEntriesById",
> +        record.messagesObjectEntriesById.withMutations(cleanUpCollection));
> +    }

this was removed in https://hg.mozilla.org/mozilla-central/rev/0f7830472380
Attachment #8908530 - Flags: review?(nchevobbe) → review+
Comment on attachment 8909343 [details]
Bug 1371721 - Keep logging repeated messages even when we reached the log-limit.

https://reviewboard.mozilla.org/r/180890/#review186466

Looks good to me, thanks for doing this Alex.
We should have tests to make sure we handle those repeated messages correctly, and also test the MESSAGES_ADD action (here http://searchfox.org/mozilla-central/source/devtools/client/webconsole/new-console-output/test/store/messages.test.js)
Attachment #8909343 - Flags: review?(nchevobbe) → review+
Comment on attachment 8909401 [details]
Bug 1371721 - Wait for redux store events before dispatching network-request-payload-ready and network-message-updated events.

https://reviewboard.mozilla.org/r/180914/#review186472
Attachment #8909401 - Flags: review?(nchevobbe) → review+
(In reply to Nicolas Chevobbe [:nchevobbe] from comment #18)
> Comment on attachment 8909343 [details]
> Bug 1371721 - Keep logging repeated messages even when we reached the
> log-limit.
> 
> https://reviewboard.mozilla.org/r/180890/#review186466
> 
> Looks good to me, thanks for doing this Alex.
> We should have tests to make sure we handle those repeated messages
> correctly,

In which type of test? also in messages.test.js?

> and also test the MESSAGES_ADD action (here
> http://searchfox.org/mozilla-central/source/devtools/client/webconsole/new-
> console-output/test/store/messages.test.js)

How do I run this test via mach??
You don't, you run it with node: 

1. cd devtools/client/webconsole
2. npm install
3. npm test
I filled bug 1401189, that's not a reasonable state to be in.

What about repeated messages, should I also contribute to messages.test.js?
It isn't crystal clear how to test that.
Comment on attachment 8909686 [details]
Bug 1371721 - Resolve dispatchMessageAdd promise only when the related message is logged.

https://reviewboard.mozilla.org/r/181210/#review186476

Looks good too.
Attachment #8909686 - Flags: review?(nchevobbe) → review+
(In reply to Nicolas Chevobbe [:nchevobbe] from comment #21)
> You don't, you run it with node: 
> 
> 1. cd devtools/client/webconsole
> 2. npm install
> 3. npm test

Fails with:

$ npm test

> webconsole@0.0.1 test /mnt/desktop/gecko/devtools/client/webconsole
> cross-env NODE_ENV=test NODE_PATH=../../../ mocha new-console-output/test/**/*.test.js --compilers js:babel-register -r jsdom-global/register -r ./new-console-output/test/require-helper.js

/mnt/desktop/gecko/devtools/client/shared/components/reps/reps.js:2411
        const bucketSize = 10 ** Math.max(2, Math.ceil(Math.log10(numProperties)) - 2);
                               ^

If I replace this double start with just one I then get this:

[BABEL] Note: The code generator has deoptimised the styling of "/mnt/desktop/gecko/devtools/client/shared/vendor/lodash.js" as it exceeds the max of "500KB".
/mnt/desktop/gecko/devtools/client/shared/components/reps/reps.js:3407
        mode: React.PropTypes.oneOf(Object.values(MODE))
                                           ^
> I filled bug 1401189, that's not a reasonable state to be in.

Agreed. We talked about it in our standup meeting yesterday.

> What about repeated messages, should I also contribute to messages.test.js ? It isn't crystal clear how to test that.

I think we should add a test in that file, yes. The idea being dispatching the MESSAGES_ADD action with an array containing ${storeLimit + X} time the same log message (so it's repeated), and check the messages store length as well as the "repeat" property.
The exponential operator requires node 8+ (same for Object.values I think)
Comment on attachment 8909686 [details]
Bug 1371721 - Resolve dispatchMessageAdd promise only when the related message is logged.

By the way, this fix may address various type of intermittents or unexpected test failures depending on dispatchMessageAdd(..., true), and so jsterm.execute:
http://searchfox.org/mozilla-central/source/devtools/client/webconsole/jsterm.js#374
Comment on attachment 8909401 [details]
Bug 1371721 - Wait for redux store events before dispatching network-request-payload-ready and network-message-updated events.

https://reviewboard.mozilla.org/r/180914/#review187092

::: devtools/client/webconsole/new-console-output/new-console-output-wrapper.js:283
(Diff revision 3)
> -    // time when to finish.
> +          // time when to finish.
> -    this.jsterm.hud.emit("network-request-payload-ready", {id, data});
> +          this.jsterm.hud.emit("network-request-payload-ready", {id, data});
> +        });
> +        this.queuedRequestUpdates = [];
> +      }
> +    }, 50);

Why we need to have this 50ms timeout?
And why we need to wait for redux store events before dispatching the 'payload-ready' event?

(I am working on bug 1395759 and this is related)

Honza
(In reply to Jan Honza Odvarko [:Honza] from comment #32)
> Why we need to have this 50ms timeout?
> And why we need to wait for redux store events before dispatching the
> 'payload-ready' event?

We aren't really waiting before dispatching payload-ready.
We are trying to aggregate multiple reduct store updates.
To do so, we use this 50ms timer, so that most of store updates that occur during a 50ms timeframe will all be done in one cycle.

This has the consequence of also delaying payload-ready event, which expect the store to be updated *before* being sent.
(At least that's my comprehension, I'm not really used to any of these codebases)
Comment on attachment 8910307 [details]
Bug 1371721 - Test messagesAdd repeat behavior.

https://reviewboard.mozilla.org/r/181788/#review187144

::: devtools/client/webconsole/new-console-output/test/store/messages.test.js:788
(Diff revision 1)
> +      expect(messages.size).toBe(2);
> +
> +      // the second one being repeated 3 times
> +      const repeat = getAllRepeatById(getState());
> +      expect(repeat[messages.first().id]).toBe(3);
> +      expect(repeat[messages.last().id]).toBe(undefined);

I'll fold this patch into the second one
"Keep logging repeated messages even when we reached the log-limit."

But I'm confused here, shouldn't it be the other way around?
getAllMessagesById order seems to be arbitrary...
or there is something wrong with this patch.
As said on IRC, the test goes like this: 

1. Add "foobar" (store: ["foobar"] )
2. Add "undefined" (store: ["foobar", undefined] )
3. Add "undefined" (store: ["foobar", undefined], with undefined repeated twice )
4. Add "undefined" (store: ["foobar", undefined], with undefined repeated 3 times )
5. Add "foobar" (store: [undefined, "foobar"], with undefined repeated 3 times )

First "foobar" is pruned because we reach logLimit, so the first message is the undefined one.
Comment on attachment 8910307 [details]
Bug 1371721 - Test messagesAdd repeat behavior.

https://reviewboard.mozilla.org/r/181788/#review187190

This looks good and has the expected behaviour :) 
Thanks for the patch Alex
Attachment #8910307 - Flags: review?(nchevobbe) → review+
Attachment #8910307 - Attachment is obsolete: true
Pushed by apoirot@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/ac6de5490c42
Create a MESSAGES_ADD action to add batches of messages at once. r=nchevobbe
https://hg.mozilla.org/integration/autoland/rev/707d860b4e2f
Keep logging repeated messages even when we reached the log-limit. r=nchevobbe
https://hg.mozilla.org/integration/autoland/rev/5997563964e1
Wait for redux store events before dispatching network-request-payload-ready and network-message-updated events. r=nchevobbe
https://hg.mozilla.org/integration/autoland/rev/48478dfbe1f8
Resolve dispatchMessageAdd promise only when the related message is logged. r=nchevobbe
Iteration: 57.3 - Sep 19 → ---
Blocks: 1399836
Depends on: 1404138
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: