1625942 - Use the ResourceWatcher API to fetch DocumentEvents

Status: RESOLVED FIXED

(DevTools :: Netmonitor, task, P1)

Description

[Alexandre Poirot [:ochameau]]

Bug 1576624 introduced the ResourceWatcher API, accessible via toolbox.resourceWatcher. This API will help listen to data that is being created early, when the document just started loading.

We should migrate the whole DevTools codebase to this API for any data that:

• DevTools frontend listen to, or care about,
  and,
• may be created or be notified early, when the document just starts being loaded.
  This data will typically be: console messages, errors, warnings, sources, Root element NodeFront, storage values, network events, stylesheets, ...

We are typically not going to use this API for:

• data being fetched on-demand, from user's input. For ex: webconsole evaluation input, or, DOM element expands from the Markup view.
• events which we only want to record when the user cares about them. For ex: animation events.

For some more high level context, please have a look at Migration to Fission-compatible APIs, which describes all Fission-related refactorings.

The typical task for this bug will be about migrating code that:

• start listening and register a RDP event listener,
• retrieve already existings data,
  from panel's codebase, to the ResourceWatcher module, in the LegacyListener object.
  And then, the panel should use the ResourceWatcher instead.

Bug 1620234 is a good example of such migration, applied to Console Messages.
Bug 1623699 is also useful example as it demonstrates how to write tests for such migration.

This bug is about focusing on only one usecase: the DocumentEvents.

This is being used by the netmonitor in order to know when each step of the document load occured (initial, DOMContentLoaded and load).

This is being listened from here:
https://searchfox.org/mozilla-central/rev/9c6e7500c0015a2c60be7b1b888261d95095ce27/devtools/client/storage/ui.js#293
https://searchfox.org/mozilla-central/rev/9c6e7500c0015a2c60be7b1b888261d95095ce27/devtools/client/netmonitor/src/connector/firefox-connector.js#287-298

Then, we might be able to use this work in order to replace the Target's navigate event.

Comment 1

[Chris Peterson [:cpeterson]]

Tracking Fission DevTools bugs for Fission Nightly (M6) milestone

Comment 2

[Daisuke Akatsuka (:daisuke)]

Attachment: Bug 1625942: Introduce ResourceWatcher into network monitor to fetch DocumentEvents.

Comment 3

[Daisuke Akatsuka (:daisuke)]

Comment on attachment 9137680 [details]
Bug 1625942: Introduce ResourceWatcher into network monitor to fetch DocumentEvents.

Hi Alex!
I have added a mechanism fetches document events into ResourceWatcher, then introduced it into network monitor.

And here, I have one question.
This implementation is just that I moved document events mechanism of webconsole to ResourceWatcher.
However, for example, as you wrote in the first comment if we should support like init (= will-navigate?) state of document, we need to add another mechanism. In order to resolve it, if we need to add something such as nsWebProgressListener, we'd better introduce new actor detecting document states? Or, will we modify DocumentEventListener of webconsole?
https://searchfox.org/mozilla-central/source/devtools/server/actors/webconsole/listeners/document-events.js

Comment 4

[Daisuke Akatsuka (:daisuke)]

And the related question.
What we should support document events are enough below?

• init (= the timing is same as will-navigate?)
• loading? (if we need all of document.readyState)
• interactive
• complete (instead of navigate of target)

Comment 5

[Daisuke Akatsuka (:daisuke)]

I'm sorry to bother you. I want to progress this, couldn't you give your feedback, please??

Comment 6

[Alexandre Poirot [:ochameau]]

(In reply to Daisuke Akatsuka (:daisuke) from comment #5)

I'm sorry to bother you. I want to progress this, couldn't you give your feedback, please??

Sorry, I'm mostly looking at phabricator requests these days and completely missed your feedback request. Do not hesitate to request for reviews on phabricator.

(In reply to Daisuke Akatsuka (:daisuke) from comment #3)

Comment on attachment 9137680 [details]
Bug 1625942: Introduce ResourceWatecher into network monitor to fetch DocumentEvents.

Hi Alex!
I have added a mechanism fetches document events into ResourceWatcher, then introduced it into network monitor.

This patch looks great, I think you can proceed with that and followup on making so that it could replace navigate.

And here, I have one question.
This implementation is just that I moved document events mechanism of webconsole to ResourceWatcher.

That is enough for the scope of this bug.

However, for example, as you wrote in the first comment if we should support like init (= will-navigate?) state of document, we need to add another mechanism. In order to resolve it, if we need to add something such as nsWebProgressListener, we'd better introduce new actor detecting document states? Or, will we modify DocumentEventListener of webconsole?
https://searchfox.org/mozilla-central/source/devtools/server/actors/webconsole/listeners/document-events.js

I think there is some confusion here. I mentioned "init", but I did not really meant it as a way to replace will-navigate. But just as a way to know when the document load started. For now, we use a very convoluted code to compute when the document started loading.

Here is a few links to track down how we compute the "init"/navigation start timing (be careful, that's a looong quest!)
https://searchfox.org/mozilla-central/rev/72e3388f74458d369af4f6cdbaeaacb719523b8c/devtools/client/netmonitor/src/reducers/timing-markers.js#24-27

  const { startedMs } = action.data;
  if (startedMs < state.firstDocumentRequestStartTimestamp) {
    nextState.firstDocumentRequestStartTimestamp = startedMs;
  }

https://searchfox.org/mozilla-central/rev/72e3388f74458d369af4f6cdbaeaacb719523b8c/devtools/client/netmonitor/src/connector/firefox-data-provider.js#81-101

      startedDateTime,
      ...
    } = data;
...
     await this.actions.addRequest(
        id,
        {
          // Convert the received date/time string to a unix timestamp.
          startedMs: Date.parse(startedDateTime),

https://searchfox.org/mozilla-central/rev/72e3388f74458d369af4f6cdbaeaacb719523b8c/devtools/server/actors/network-monitor/network-observer.js#659-662

    event.startedDateTime = (timestamp
      ? new Date(Math.round(timestamp / 1000))
      : new Date()
    ).toISOString();

https://searchfox.org/mozilla-central/rev/72e3388f74458d369af4f6cdbaeaacb719523b8c/devtools/server/actors/network-monitor/network-observer.js#797

 this._createNetworkEvent(channel, { timestamp, extraStringData });

https://searchfox.org/mozilla-central/rev/72e3388f74458d369af4f6cdbaeaacb719523b8c/devtools/server/actors/network-monitor/network-observer.js#584

  observeActivity: DevToolsUtils.makeInfallible(function(
    channel,
    activityType,
    activitySubtype,
    timestamp,
    extraSizeData,
    extraStringData
  ) {
...
this._onRequestHeader(channel, timestamp, extraStringData);

We could probably use navigationStart timestamp, coming from this interface:
https://searchfox.org/mozilla-central/source/dom/webidl/PerformanceTiming.webidl#15-35
And expose it the same way we expose domInteractive:
https://searchfox.org/mozilla-central/source/devtools/server/actors/webconsole/listeners/document-events.js#71-80
And domComplete:
https://searchfox.org/mozilla-central/source/devtools/server/actors/webconsole/listeners/document-events.js#90-99

This would only help reducing the complexity of firstDocumentRequestStartTimestamp computation and would make it more similar to the computation of firstDocumentDOMContentLoadedTimestamp and firstDocumentLoadTimestamp.

But, this is not meant to replace will-navigate. With Fission refactoring, will-navigate should eventually be completely replaced by onTargetAvailable. Bug 1593937, is going to introduce the first Target to be created once per navigation. This mean that for each navigation, we will have a onTargetAvailable call. This should make will-navigate become useless. But bug 1593937 is only going to make this lifecycle change only for additional frame target. We are not going to change the lifecycle of the top level target just yet.

This DOCUMENT_EVENTS resource is rather a safer equivalent to navigate, as we discussed over here:
https://phabricator.services.mozilla.com/D67438#inline-408439
Compared to listening to navigate via target.on("navigate"), where you might miss an early navigate event if the target just got created.
DOCUMENT_EVENTS doesn't suffer from that, as we emit a documentEvent RDP event and a DOCUMENT_EVENTS Resource even if the page is already loaded.

To conclude, I believe you current patch is great and is enough to unlock you in https://phabricator.services.mozilla.com/D67438#inline-408439
If not, please let me know what I missed.
https://phabricator.services.mozilla.com/D67438#inline-408439

Comment 7

[Daisuke Akatsuka (:daisuke)]

Attachment: Bug 1625942: Add a browser test for document events ResourceWatcher.

Depends on D69329

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/743e1ce65e06
Introduce ResourceWatcher into network monitor to fetch DocumentEvents. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/4255bd054e34
Add a browser test for document events ResourceWatcher. r=ochameau

Comment 9

[Daniel Varga [:dvarga]]

Backed out 2 changesets (Bug 1625942) for causing devtools failures at devtools/client/netmonitor/test/browser_net_reload-markers.js

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=298067796&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=4255bd054e34fcaf2a5e5d2c9b1dba9f2fe4e2d8

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=298059789&repo=autoland&lineNumber=22660

Backout link: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=298067062&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=54789c4c8fcbfd4f1fc4827ae2c10791815ad39a

[task 2020-04-17T09:16:31.010Z] 09:16:31     INFO - TEST-PASS | devtools/client/netmonitor/test/browser_net_reload-markers.js | Reloading finished - 
[task 2020-04-17T09:16:31.010Z] 09:16:31     INFO - Buffered messages finished
[task 2020-04-17T09:16:31.010Z] 09:16:31     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_reload-markers.js | The first received marker is correct. - Got dom-loading, expected dom-interactive
[task 2020-04-17T09:16:31.010Z] 09:16:31     INFO - Stack trace:
[task 2020-04-17T09:16:31.010Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:test_is:1297
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_reload-markers.js:null:26
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1039
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:904
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_reload-markers.js | The second received marker is correct. - Got dom-interactive, expected dom-complete
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - Stack trace:
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:test_is:1297
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochitests/content/browser/devtools/client/netmonitor/test/browser_net_reload-markers.js:null:31
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1039
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1074
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:904
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - GECKO(5304) | [Child 5880: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 018AF400 == 0 [pid = 5880] [id = {25006773-c3f4-46ac-aa3d-9891a022e72d}] [url = about:blank]
[task 2020-04-17T09:16:31.011Z] 09:16:31     INFO - Destroying the specified network monitor.
[task 2020-04-17T09:16:31.012Z] 09:16:31     INFO - Wait for completion of all NetworkUpdateEvents packets...
[task 2020-04-17T09:16:31.072Z] 09:16:31     INFO - All pending requests finished.
[task 2020-04-17T09:16:31.092Z] 09:16:31     INFO - GECKO(5304) | console.error: "Task cancelled"
[task 2020-04-17T09:16:31.912Z] 09:16:31     INFO - GECKO(5304) | [Child 3528: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0D189000) [pid = 3528] [serial = 372] [outer = 00000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_simple-test-page.html]
[task 2020-04-17T09:16:31.912Z] 09:16:31     INFO - GECKO(5304) | [Child 3528: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0D184800) [pid = 3528] [serial = 371] [outer = 00000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_simple-test-page.html]
[task 2020-04-17T09:16:31.912Z] 09:16:31     INFO - GECKO(5304) | [Child 3528: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (0D15DC00) [pid = 3528] [serial = 370] [outer = 00000000] [url = about:blank]
[task 2020-04-17T09:16:31.912Z] 09:16:31     INFO - GECKO(5304) | [Child 3528: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 071D9000 == 1 [pid = 3528] [id = {1135a3c8-9c5e-4b3f-87c0-5f12fb99ced2}] [url = http://example.com/browser/devtools/client/netmonitor/test/html_simple-test-page.html]
[task 2020-04-17T09:16:31.987Z] 09:16:31     INFO - GECKO(5304) | [Child 3528: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (07113100) [pid = 3528] [serial = 365] [outer = 00000000] [url = http://example.com/browser/devtools/client/netmonitor/test/html_post-data-test-page.html]
[task 2020-04-17T09:16:32.582Z] 09:16:32     INFO - GECKO(5304) | [Child 5188: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 018B8800 == 1 [pid = 5188] [id = {19ee66c8-7c63-4e5e-b4f7-ce84181ec964}] [url = about:blank]
[task 2020-04-17T09:16:32.625Z] 09:16:32     INFO - GECKO(5304) | [Child 5188: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (074F1C00) [pid = 5188] [serial = 152] [outer = 00000000] [url = http://example.com/browser/devtools/client/netmonitor/test/sjs_simple-unsorted-cookies-test-server.sjs]
[task 2020-04-17T09:16:32.625Z] 09:16:32     INFO - GECKO(5304) | [Child 5188: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0BED8800) [pid = 5188] [serial = 157] [outer = 00000000] [url = about:blank]
[task 2020-04-17T09:16:34.193Z] 09:16:34     INFO - GECKO(5304) | [Parent 2760: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 59 (164BDC00) [pid = 2760] [serial = 528] [outer = 00000000] [url = about:blank]
[task 2020-04-17T09:16:34.193Z] 09:16:34     INFO - GECKO(5304) | [Parent 2760: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0F273000 == 14 [pid = 2760] [id = {8ff4a829-93c3-4931-a532-45bb3631cdc3}] [url = about:devtools-toolbox]
[task 2020-04-17T09:16:34.308Z] 09:16:34     INFO - Removing tab.

Comment 10

[Pulsebot]

Backout by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/84a01c8388d5
Backed out 2 changesets for causing devtools failures at devtools/client/netmonitor/test/browser_net_reload-markers.js

Comment 11

[Daisuke Akatsuka (:daisuke)]

Attachment: Bug 1625942: Introduce dom-loading event.

Depends on D69329

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3e7ece9f761e
Introduce ResourceWatcher into network monitor to fetch DocumentEvents. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/f9527efad858
Introduce dom-loading event. r=ochameau,Honza
https://hg.mozilla.org/integration/autoland/rev/6e1e4190acc3
Add a browser test for document events ResourceWatcher. r=ochameau

Comment 13

[Oana Pop-Rus]

https://hg.mozilla.org/mozilla-central/rev/3e7ece9f761e
https://hg.mozilla.org/mozilla-central/rev/f9527efad858
https://hg.mozilla.org/mozilla-central/rev/6e1e4190acc3