1434855 - HAR export is very slow

Status: RESOLVED FIXED

(DevTools :: Netmonitor, defect, P2)

Description

[Alexandre Poirot [:ochameau]]

STR:
* open netmonitor
* visit duckduckgo.com
* Right click on any request
* Click on "Save all as HAR"

Here it takes about 10 seconds before the file save dialog appears.

Here is a profile of such STR:
  https://perfht.ml/2npGY8N
Both parent and content processes aren't very busy. They are mostly waiting.
There is a lot of very small react updates that accumulates, but that doesn't explain such long delay.

Everytime we request a lazy attribute like response content, headers, cookies, ...
redux store is updated and react then also checks for updates.
There is no reflows being done. It is only redux and especially react work to check for updates.
For example, the StatusBar, as a pure function gets its render method called n-times for each request. 'n' being equal to the number of lazy attribute we fetch.
bug 1434848 is opened to optimize this. But there is other React components trying to update, like RequestListContent. This one will be harder to optimize.

So we can optimize all this, but that is not the main reason why this feature is so slow. The reason is that when HAR calls connector's `requestData`, it waits for redux actions to complete:
  https://searchfox.org/mozilla-central/source/devtools/client/netmonitor/src/connector/firefox-data-provider.js#417-424
  https://searchfox.org/mozilla-central/source/devtools/client/netmonitor/src/connector/firefox-data-provider.js#124
If I comment them both, the same STR takes only 2 to 3 seconds to complete.
I imagine redux action only complete after the action is really dispatched, after the throttling. So if we have "n" requests, and we fetch for "x" lazy attributes it will wait for n*50ms*x.

duckduckgo.com spawn 18 requests and at first sight, HAR fetches 7 attributes lazily, so 18*7*50 = 6.3 seconds.

Comment 1

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: Bug 1434855 - Refactor HAR builder options;

Review commit: https://reviewboard.mozilla.org/r/224344/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/224344/

Comment 2

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Alex, here are some comments:

- The patch focuses on avoiding the timeouts.
- I'd like to keep the patch simple and land it yet in 60 (or uplift)
- So, all other improvements should be filled as follow ups (if not already)
- I am also working on extending DAMP test (bug 1434849), but this bug should land first. The DAMP test is too slow for complicated.netmonitor

Honza

Comment 3

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Try push:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a93226925ce403e98b6504760075a8d465c9eade

Honza

Comment 4

[Alexandre Poirot [:ochameau]]

Comment on attachment 8955186 [details]
Bug 1434855 - Refactor HAR builder options;

https://reviewboard.mozilla.org/r/224344/#review230922

Works great! Please just make this patch less hacky as suggested in next comment.

> - So, all other improvements should be filled as follow ups (if not already)

Do you have in mind some followups?

::: devtools/client/netmonitor/src/har/har-exporter.js:200
(Diff revision 1)
> +      form: { title, url }
> +    } = getTabTarget();
> +
> +    // Disconnect from redux actions/store.
> +    let actions = connector.connector.dataProvider.actions;
> +    connector.connector.dataProvider.actions = {};

A couple of comments here:
- Please consider splitting your patches within bugs. (You don't have to attach only one patch per bug)
The important modification you do is right here and in line 214, where you reset action property.
This is hidden by the rest of your patch which is the refactoring of `buildHarData`'s `options` arguments.
- This is too hacky. You are playing from `HarExporter` with `FirefoxDataProvider` internals. You should address that in this patch, not in a followup. You should expose helpers on `FirefoxDataProvider` to make that hack explicit from firefox-data-provider.js. Like adding `FirefoxDataProvider.{start|stop}ReduxUpdates()` or similar.
- Don't you think we should try to keep doing the redux updates? By disabling it, it means that the UI will redo the RDP request that HAR already did. This is good fit for followup.
- Note that in the current form, FirefoxDataProvider can be instanciated outside of netmonitor UI if that helps simplifying HAR codebase when run without a toolbox. It just expect a `webConsoleClient` and `actions` can be set to such empty object. We can consider moving this module outside of netmonitor ui, it looks more like a client helper. May be https://searchfox.org/mozilla-central/source/devtools/shared/webconsole, next to console client. (it might also help the webextension usage)

Comment 5

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: Bug 1434855 - Improve performance of HAR export;

Review commit: https://reviewboard.mozilla.org/r/225430/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/225430/

Comment 6

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 8955186 [details]
Bug 1434855 - Refactor HAR builder options;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/224344/diff/1-2/

Comment 7

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Alexandre Poirot [:ochameau] from comment #4)
> Do you have in mind some followups?
I have been thinking mostly about better way how to avoid
the timeouts e.g. instead of avoiding redux updates (by not
firing redux actions), we could rather customize the batching
middle-ware or do something better.

> 
> ::: devtools/client/netmonitor/src/har/har-exporter.js:200
> (Diff revision 1)
> > +      form: { title, url }
> > +    } = getTabTarget();
> > +
> > +    // Disconnect from redux actions/store.
> > +    let actions = connector.connector.dataProvider.actions;
> > +    connector.connector.dataProvider.actions = {};
> 
> A couple of comments here:
> - Please consider splitting your patches within bugs. (You don't have to
> attach only one patch per bug)
> The important modification you do is right here and in line 214, where you
> reset action property.
> This is hidden by the rest of your patch which is the refactoring of
> `buildHarData`'s `options` arguments.
Done

> - This is too hacky. You are playing from `HarExporter` with
> `FirefoxDataProvider` internals. You should address that in this patch, not
> in a followup. You should expose helpers on `FirefoxDataProvider` to make
> that hack explicit from firefox-data-provider.js. Like adding
> `FirefoxDataProvider.{start|stop}ReduxUpdates()` or similar.
Yes, done

> - Don't you think we should try to keep doing the redux updates? By
> disabling it, it means that the UI will redo the RDP request that HAR
> already did. This is good fit for followup.
Created bug 1443567

> - Note that in the current form, FirefoxDataProvider can be instanciated
> outside of netmonitor UI if that helps simplifying HAR codebase when run
> without a toolbox. It just expect a `webConsoleClient` and `actions` can be
> set to such empty object. We can consider moving this module outside of
> netmonitor ui, it looks more like a client helper. May be
> https://searchfox.org/mozilla-central/source/devtools/shared/webconsole,
> next to console client. (it might also help the webextension usage)
Yep, sounds good to me, I need to thing a bit more about this.

Thanks for the review Alex!

Honza

Comment 8

[Alexandre Poirot [:ochameau]]

Comment on attachment 8956519 [details]
Bug 1434855 - Improve performance of HAR export;

https://reviewboard.mozilla.org/r/225430/#review231622

Thanks a lot for the changeset split. It really eases the review!
I wasn't expecting you to do it after the fact.
It was more a suggestion for next patches ;)

::: devtools/client/netmonitor/src/connector/firefox-data-provider.js:42
(Diff revision 1)
>      // Event handlers
>      this.onNetworkEvent = this.onNetworkEvent.bind(this);
>      this.onNetworkEventUpdate = this.onNetworkEventUpdate.bind(this);
>    }
>  
> +  enableActions(enable) {

A brief comment about the purpose of this method here would be helpful.

Comment 9

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 8955186 [details]
Bug 1434855 - Refactor HAR builder options;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/224344/diff/2-3/

Comment 10

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 8956519 [details]
Bug 1434855 - Improve performance of HAR export;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/225430/diff/1-2/

Comment 11

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Alexandre Poirot [:ochameau] from comment #8)
> Thanks a lot for the changeset split. It really eases the review!
> I wasn't expecting you to do it after the fact.
> It was more a suggestion for next patches ;)
I am always happy to make the review easier :-)

> > +  enableActions(enable) {
> 
> A brief comment about the purpose of this method here would be helpful.
Done

Honza

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a87683b49741
Refactor HAR builder options; r=ochameau
https://hg.mozilla.org/integration/autoland/rev/ceea3f9776b1
Improve performance of HAR export; r=ochameau

Comment 13

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backed out for failing browser-chrome's browser/components/extensions/test/browser/browser_ext_devtools_network.js:

https://hg.mozilla.org/integration/autoland/rev/4d03290053fc523b65eb3193f53333b71be906ca

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=ceea3f9776b1887dcfe3135778b8234b38f9f0d8&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Log: https://treeherder.mozilla.org/logviewer.html#?job_id=166543760&repo=autoland

18:12:59     INFO -  317 INFO TEST-PASS | browser/components/extensions/test/browser/browser_ext_devtools_network.js | The resolved value is equal to the one received in the callback API mode -
18:12:59     INFO -  318 INFO Leaving test bound test_devtools_network_on_request_finished
18:12:59     INFO -  Buffered messages finished
18:12:59    ERROR -  319 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_devtools_network.js | message queue is empty - Got ["onRequestFinished-callbackExecuted","onRequestFinished-promiseResolved"], expected []
18:12:59     INFO -  Stack trace:
18:12:59     INFO -      chrome://mochikit/content/browser-test.js:test_is:1271
18:12:59     INFO -      chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:27
18:12:59     INFO -      chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:666
18:12:59     INFO -      testScope/test_finish/<@chrome://mochikit/content/browser-test.js:1363:11
18:12:59     INFO -      run@chrome://mochikit/content/browser-test.js:1300:9

Comment 14

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 8955186 [details]
Bug 1434855 - Refactor HAR builder options;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/224344/diff/3-4/

Comment 15

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Comment on attachment 8956519 [details]
Bug 1434855 - Improve performance of HAR export;

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/225430/diff/2-3/

Comment 16

[Jan Honza Odvarko [:Honza] (always need-info? me)]

The test should be fixed now, relanding...
Honza

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/73628e4869b3
Refactor HAR builder options; r=ochameau
https://hg.mozilla.org/integration/autoland/rev/470c96bdde51
Improve performance of HAR export; r=ochameau

Comment 18

[Cristian Brindusan [:cbrindusan]]

https://hg.mozilla.org/mozilla-central/rev/73628e4869b3
https://hg.mozilla.org/mozilla-central/rev/470c96bdde51