Closed Bug 1637641 Opened 5 months ago Closed 5 months ago

Cache resources in the ResourceWatcher so that subsequent calls to `watch` also notify about previously received resources

Categories

(DevTools :: Framework, enhancement)

enhancement

Tracking

(Fission Milestone:M6c, firefox78 fixed)

RESOLVED FIXED
Firefox 78
Fission Milestone M6c
Tracking Status
firefox78 --- fixed

People

(Reporter: ochameau, Assigned: daisuke)

References

(Blocks 1 open bug)

Details

(Whiteboard: dt-fission-m2-mvp)

Attachments

(2 files)

Bug 1625961 highlighted that watch was inconsistant, and while the first call would notify about past and future resources, all other calls after the first one would only notify about the future ones.

This ends up being an issue in bug 1625909 and bug 1625957.

  • For Network Events, the existing codebase listen for network events from multiple places. And it uses a cache of network events which have been fired since the toolbox has been opened, from FirefoxConnector and WebConsoleConnectionProxy.
  • For CSS Changes, we are fetching the changes from two places in parallel. From ChangesView and CompatibilityView. This is not perfect as we duplicate the fetching of changes if the two panels are opened.

For the Network Events, we should move the current cache, which is on the WebConsoleFront, to the ResourceWatcher. That's because when we will migrate the network event listening to the server side, we will no longer emit the network events throught the WebConsoleFront and so this Map will no longer be used.
And for CSS Changes, we have to ensure that watch work properly from more than one callsite, and fetch already existing changes. This can only be done through a cache, fetching all the changes twice doesn't look like something we should keep doing.

Implementing a trivial cache, which hold all resources will be easy.
Implementing one which limits the number of resources we hold in it, in order to prevent leaking all of them, will be harder.

For the CSS Changes, it is quite easy. We do clear the resources each time we navigate to a new page. So, we can clear CSS Changes resources each time we have a will-navigate event (or any equivalent).
For Network Events, interestingly, while the cached requests are being used by both console and netmonitor, this is only cleared by the webconsole codebase. The WebConsoleFront Map is clear on will-navigate as well, but also on a few user interactions: console.clear and clear button (and may be some other user actions?).

In both cases, we clear all resources, there is so filtering. We clear all resources for all inner iframes, anytime the top level document navigates.
It may highlight some breakage on the Browser Toolbox if, for some reason browser.xhtml navigates. We will receive a will-navigate when using the reload development feature. This will remove all resources, even if content processes and other top level windows in the parent process are still around.
This may not be an issue with existing code, but can start being one if we apply that to all resources. We might use a per-target cache.

So given the current codebase, I would suggest implementing a cache which is automatically purged whenever we:

  • receive will-navigate event on the top level target (We can use DOCUMENT_EVENTS's dom-complete, or wait for a conclusion from bug 1632141. See also the followup section). Note that for some resources, we may want to avoid clearing the cache. See this code. I'm trying to cover this in detial in the last paragraph.
  • on-demand, from panel codebase, via an api like this ResourceWatcher.clearResources(resourceType)

We may followup in order to:

  • also clear per target via onTargetDestroyed
  • use something else than will-navigate in order to be fission compatible, but this may be redundant with previous point and onTargetDestroyed. We can clear everything when receiving onTargetDestroyed for the top level target.
  • once we have server side implementation of resources, we may add a request, for clearing resources on the server when clearResources is called.
  • clear the cache of individual resources from server events. For example, for CSS Changes "remove-change" event. Or storage's "store-cleared" event.

Note that this cache isn't meant to reflect one panel visual state.
I believe this should rather focus on containing the resources which are still debuggable. i.e. resources which are still alive in the debugging context and that we can still inspect via actors. And so it should rather be cleaned either when:

  • we know, from the server state, that the resource is gone
  • we know, from the frontend state that there is no way to see/debug this resource and we can free up a few bytes by eagerly clearing them

The persist logs/requests attribute is controvertial here. We can clear the ResourceWatcher cache on each navigation and still implement it correctly.
If the panel registers a listener, it will still receive resources for each document, navigation after navigation. It is up to the panel code to clear its own store, often a redux store accordingly to the persist attribute.
The only thing to note here is that we won't have all resources for all the navigations and all individual document instances when we open the panel for the first time. Instead we will only receive the resources for the current document. But then once opened, we will receive resources for all following navigations.
We may have the same way of thinking regarding clearance made from panel's codebase, like clear buttons. We may only prune panel's store and keep ResourceWatcher cache as-is, if another panel may still use these resource we are about to clear.

Tracking dt-fission-m2-mvp bugs for Fission Nightly milestone (M6c)

Fission Milestone: --- → M6c

bomsy started prototyping a very trivial cache in https://phabricator.services.mozilla.com/D71543.
It allows to investigate how to migrate the netmonitor to the ResourceWatcher API and it ignores most of the complexity of caching, which is around clearing. But it can be taken as an example of first basic implementation.

Assignee: nobody → daisuke
Status: NEW → ASSIGNED
Blocks: 1640886
Attachment #9150976 - Attachment description: Bug 1637641: [WIP] Make multiple listeners can receive proper cached resources. → Bug 1637641: Make multiple listeners can receive proper cached resources.
Pushed by dakatsuka.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/b6fabe763177
Make multiple listeners can receive proper cached resources. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/ce69538af12e
Add test for the cache mechanism in ResourceWatcher. r=ochameau

Backed out for failures on browser_resources_client_caching.js

backout: https://hg.mozilla.org/integration/autoland/rev/272e3c98d0029fe73c0a57c45bc3b11ffa0e2bee

push: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=ce69538af12e6d3eadcd61bdb5f92a96749c939b&group_state=expanded&selectedTaskRun=Y4NTor0VRGmp2n1WU2Jk3A-0

Failed on tier 1 on the next push after this landed https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=9e1ecd2a9947b8937dd8319cca74bbbfcb269e40&searchStr=linux%2C18.04%2Cx64%2Cdebug%2Cmochitests%2Ctest-linux1804-64%2Fdebug-mochitest-devtools-chrome-e10s-4%2Cm%28dt4%29

failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304085872&repo=autoland&lineNumber=9410

[task 2020-05-28T09:43:50.932Z] 09:43:50 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "data:text/html,Cache Test" line: 0}]
[task 2020-05-28T09:43:50.932Z] 09:43:50 INFO - Register first listener to get all available resources
[task 2020-05-28T09:43:50.932Z] 09:43:50 INFO - Add messages as console message
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - Add message as error message
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - Console message: [JavaScript Error: "TypeError: document.doTheImpossible is not a function" {file: "data:text/html,Cache Test" line: 1}]
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - @data:text/html,Cache Test:1:10
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - frameScript@resource://testing-common/content-task.js line 110 > eval:7:5
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - @resource://testing-common/content-task.js:111:29
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - MessageListener.receiveMessage*@resource://testing-common/content-task.js:64:19
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO -
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - Add messages as console message again
[task 2020-05-28T09:43:50.933Z] 09:43:50 INFO - Register listener to get the cached resources
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - Buffered messages finished
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - TEST-UNEXPECTED-FAIL | devtools/shared/resources/tests/browser_resources_client_caching.js | Number of the available resources is correct - Got 5, expected 6
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - Stack trace:
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochikit/content/browser-test.js:test_is:1327
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochitests/content/browser/devtools/shared/resources/tests/browser_resources_client_caching.js:null:192
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1064
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1104
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:921
[task 2020-05-28T09:43:50.939Z] 09:43:50 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:918
[task 2020-05-28T09:43:50.940Z] 09:43:50 INFO - TEST-PASS | devtools/shared/resources/tests/browser_resources_client_caching.js | Number of the resources is correct -
[task 2020-05-28T09:43:50.940Z] 09:43:50 INFO - TEST-PASS | devtools/shared/resources/tests/browser_resources_client_caching.js | The 0th resource is correct -

Flags: needinfo?(daisuke)
Flags: needinfo?(daisuke)
Pushed by dakatsuka.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/74e74024568d
Make multiple listeners can receive proper cached resources. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/771431dbcec2
Add test for the cache mechanism in ResourceWatcher. r=ochameau
Flags: needinfo?(daisuke)
Flags: needinfo?(daisuke)
Pushed by dakatsuka.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/f3bad0efa582
Make multiple listeners can receive proper cached resources. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/c8c30f4dc5e3
Add test for the cache mechanism in ResourceWatcher. r=ochameau

Backed out 2 changesets (bug 1637641) for many devtools failures

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&fromchange=c8c30f4dc5e35b6eda1158f54aa8bde7a91ff5cc&searchStr=devtools&tochange=262535660385969128ce50a0b4f8867fdbcad450&selectedTaskRun=V6DaMy8cRTWn1JIUnmNI7Q-0

Backout link: https://hg.mozilla.org/integration/autoland/rev/262535660385969128ce50a0b4f8867fdbcad450

Failures logs:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304240917&repo=autoland&lineNumber=1872

[task 2020-05-29T10:37:21.350Z] 10:37:21     INFO - TEST-START | devtools/client/dom/test/browser_dom_nodes_select.js
[task 2020-05-29T10:37:21.388Z] 10:37:21     INFO - GECKO(1253) | [Child 1525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f3c63580000 == 1 [pid = 1525] [id = {a5348690-f7e7-4e95-9d51-009b374ce166}]
[task 2020-05-29T10:37:21.388Z] 10:37:21     INFO - GECKO(1253) | [Child 1525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f3c7e993350) [pid = 1525] [serial = 3] [outer = (nil)]
[task 2020-05-29T10:37:21.388Z] 10:37:21     INFO - GECKO(1253) | [Child 1525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f3c635d0000) [pid = 1525] [serial = 4] [outer = 0x7f3c7e993350]
[task 2020-05-29T10:37:21.536Z] 10:37:21     INFO - GECKO(1253) | [Child 1525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f3c635d8000) [pid = 1525] [serial = 5] [outer = 0x7f3c7e993350]
[task 2020-05-29T10:37:21.921Z] 10:37:21     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f7eca119000 == 9 [pid = 1253] [id = {129a7cc6-8a8f-49a7-a7b9-cc36a82fadd8}]
[task 2020-05-29T10:37:21.922Z] 10:37:21     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (0x7f7eecca19f0) [pid = 1253] [serial = 35] [outer = (nil)]
[task 2020-05-29T10:37:21.926Z] 10:37:21     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 23 (0x7f7eca16d800) [pid = 1253] [serial = 36] [outer = 0x7f7eecca19f0]
[task 2020-05-29T10:37:22.002Z] 10:37:22     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 24 (0x7f7ed72ee000) [pid = 1253] [serial = 37] [outer = 0x7f7eecca19f0]
[task 2020-05-29T10:37:22.102Z] 10:37:22     INFO - GECKO(1253) | [Parent 1253, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp, line 3734
[task 2020-05-29T10:37:22.513Z] 10:37:22     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f7eca16dc00 == 10 [pid = 1253] [id = {13302dc3-19c6-496d-a738-02a4dc969c98}]
[task 2020-05-29T10:37:22.513Z] 10:37:22     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 25 (0x7f7eecca2a40) [pid = 1253] [serial = 38] [outer = (nil)]
[task 2020-05-29T10:37:22.513Z] 10:37:22     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 26 (0x7f7eca170800) [pid = 1253] [serial = 39] [outer = 0x7f7eecca2a40]
[task 2020-05-29T10:37:23.439Z] 10:37:23     INFO - GECKO(1253) | [Child 1525, Main Thread] WARNING: CacheStorage not supported on untrusted origins.: file /builds/worker/checkouts/gecko/dom/cache/CacheStorage.cpp, line 167
[task 2020-05-29T10:37:24.568Z] 10:37:24     INFO - GECKO(1253) | [Child 1711: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fcd5ddcb400) [pid = 1711] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:25.973Z] 10:37:25     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f7ee71f7000 == 11 [pid = 1253] [id = {543e587d-bc07-4187-b6ea-61658c096063}]
[task 2020-05-29T10:37:25.977Z] 10:37:25     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 27 (0x7f7eecca09a0) [pid = 1253] [serial = 40] [outer = (nil)]
[task 2020-05-29T10:37:25.977Z] 10:37:25     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 28 (0x7f7ee8884800) [pid = 1253] [serial = 41] [outer = 0x7f7eecca09a0]
[task 2020-05-29T10:37:26.193Z] 10:37:26     INFO - GECKO(1253) | [Parent 1253, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004001 (NS_ERROR_NOT_IMPLEMENTED): file /builds/worker/checkouts/gecko/dom/xul/nsXULPrototypeCache.cpp, line 235
[task 2020-05-29T10:37:26.221Z] 10:37:26     INFO - GECKO(1253) | console.error: "Store does not have a valid reducer. Make sure the argument passed to combineReducers is an object whose values are reducers."
[task 2020-05-29T10:37:26.704Z] 10:37:26     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 27 (0x7f7ee789fa90) [pid = 1253] [serial = 22] [outer = (nil)] [url = about:robots]
[task 2020-05-29T10:37:26.705Z] 10:37:26     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 26 (0x7f7eecca12b0) [pid = 1253] [serial = 25] [outer = (nil)] [url = about:devtools-toolbox]
[task 2020-05-29T10:37:26.705Z] 10:37:26     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f7edf0c9400 == 10 [pid = 1253] [id = {c76b5fdd-e94a-4d01-aeba-2d1f65cb360d}] [url = about:robots]
[task 2020-05-29T10:37:27.323Z] 10:37:27     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 25 (0x7f7eecca1820) [pid = 1253] [serial = 28] [outer = (nil)] [url = chrome://devtools/content/dom/index.html]
[task 2020-05-29T10:37:28.195Z] 10:37:28     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f7eca112c00 == 9 [pid = 1253] [id = {6e55194f-fb81-4853-8db5-54265113fdcb}] [url = about:devtools-toolbox]
[task 2020-05-29T10:37:28.195Z] 10:37:28     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f7eca166c00 == 8 [pid = 1253] [id = {b485ec50-7f98-4d77-b0e7-70019d35e00e}] [url = chrome://devtools/content/dom/index.html]
[task 2020-05-29T10:37:28.235Z] 10:37:28     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 24 (0x7f7edeee2400) [pid = 1253] [serial = 29] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:28.243Z] 10:37:28     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 23 (0x7f7eca116000) [pid = 1253] [serial = 31] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:28.244Z] 10:37:28     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (0x7f7ee48dbc00) [pid = 1253] [serial = 24] [outer = (nil)] [url = about:robots]
[task 2020-05-29T10:37:29.224Z] 10:37:29     INFO - GECKO(1253) | [Child 1441: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f5470981000 == 1 [pid = 1441] [id = {e92aa051-ecea-4b8c-b8e9-7948daa9e920}] [url = http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html]
[task 2020-05-29T10:37:29.385Z] 10:37:29     INFO - GECKO(1253) | [Child 1760: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7ff7ad2d8400 == 0 [pid = 1760] [id = {fcde0fbd-0898-41b2-b083-e5270ec76656}] [url = about:blank]
[task 2020-05-29T10:37:29.426Z] 10:37:29     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (0x7f7eecca24d0) [pid = 1253] [serial = 33] [outer = (nil)] [url = chrome://devtools/content/dom/index.html]
[task 2020-05-29T10:37:29.441Z] 10:37:29     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (0x7f7eecca0b70) [pid = 1253] [serial = 30] [outer = (nil)] [url = about:devtools-toolbox]
[task 2020-05-29T10:37:29.457Z] 10:37:29     INFO - GECKO(1253) | [Child 1441: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f548bd93180) [pid = 1441] [serial = 5] [outer = (nil)] [url = http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html]
[task 2020-05-29T10:37:29.815Z] 10:37:29     INFO - GECKO(1253) | [Child 1441: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f54709b3400) [pid = 1441] [serial = 9] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:29.815Z] 10:37:29     INFO - GECKO(1253) | [Child 1441: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f54709b8800) [pid = 1441] [serial = 7] [outer = (nil)] [url = http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html]
[task 2020-05-29T10:37:30.092Z] 10:37:30     INFO - GECKO(1253) | [Child 1760: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7ff7c2f93350) [pid = 1760] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:32.944Z] 10:37:32     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x7f7ef504f000) [pid = 1253] [serial = 27] [outer = (nil)] [url = about:devtools-toolbox]
[task 2020-05-29T10:37:32.968Z] 10:37:32     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f7eca16d800) [pid = 1253] [serial = 36] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:32.969Z] 10:37:32     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f7eca166400) [pid = 1253] [serial = 32] [outer = (nil)] [url = about:devtools-toolbox]
[task 2020-05-29T10:37:32.970Z] 10:37:32     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f7eca16a400) [pid = 1253] [serial = 34] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:34.130Z] 10:37:34     INFO - GECKO(1253) | [Child 1760: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7ff7a7b84400) [pid = 1760] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:37:45.777Z] 10:37:45     INFO - GECKO(1253) | [Child 1525: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f3c635d0000) [pid = 1525] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:38:51.460Z] 10:38:51     INFO - TEST-INFO | started process screentopng
[task 2020-05-29T10:38:51.722Z] 10:38:51     INFO - TEST-INFO | screentopng: exit 0
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Buffered messages logged at 10:37:21
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Entering test bound 
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Test DOM panel node highlight started
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Adding a new test tab with URL: 'http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html'
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Tab added and finished loading
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Loading the helper frame script chrome://mochitests/content/browser/devtools/client/shared/test/frame-script-utils.js
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Buffered messages logged at 10:37:22
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Buffered messages logged at 10:37:25
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Console message: [JavaScript Warning: "onmozfullscreenchange is deprecated." {file: "http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html" line: 0}]
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Console message: [JavaScript Warning: "onmozfullscreenerror is deprecated." {file: "http://example.com/browser/devtools/client/dom/test/page_dom_nodes.html" line: 0}]
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - TEST-PASS | devtools/client/dom/test/browser_dom_nodes_select.js | The DOM panel is already populated - 
[task 2020-05-29T10:38:51.723Z] 10:38:51     INFO - Buffered messages logged at 10:37:27
[task 2020-05-29T10:38:51.724Z] 10:38:51     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:51.724Z] 10:38:51     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:51.724Z] 10:38:51     INFO - Buffered messages finished
[task 2020-05-29T10:38:51.725Z] 10:38:51     INFO - TEST-UNEXPECTED-FAIL | devtools/client/dom/test/browser_dom_nodes_select.js | Test timed out - 
[task 2020-05-29T10:38:52.720Z] 10:38:52     INFO - Removing tab.
[task 2020-05-29T10:38:52.721Z] 10:38:52     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2020-05-29T10:38:52.759Z] 10:38:52     INFO - Got event: 'TabClose' on [object XULElement].
[task 2020-05-29T10:38:52.841Z] 10:38:52     INFO - GECKO(1253) | [Parent 1253, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/JSWindowActorProtocol.cpp, line 172
[task 2020-05-29T10:38:52.841Z] 10:38:52     INFO - GECKO(1253) | [Parent 1253, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/JSWindowActorProtocol.cpp, line 172
[task 2020-05-29T10:38:52.848Z] 10:38:52     INFO - Tab removed and finished closing
[task 2020-05-29T10:38:52.886Z] 10:38:52     INFO - GECKO(1253) | [Parent 1253: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f7ee71f7000 == 7 [pid = 1253] [id = {543e587d-bc07-4187-b6ea-61658c096063}] [url = chrome://devtools/content/inspector/index.xhtml]
[task 2020-05-29T10:38:52.902Z] 10:38:52     INFO - TEST-PASS | devtools/client/dom/test/browser_dom_nodes_select.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2020-05-29T10:38:52.902Z] 10:38:52     INFO - finish() was called, cleaning up...
[task 2020-05-29T10:38:52.930Z] 10:38:52     INFO - GECKO(1253) | MEMORY STAT | vsize 3233MB | residentFast 422MB | heapAllocated 138MB
[task 2020-05-29T10:38:52.930Z] 10:38:52     INFO - TEST-OK | devtools/client/dom/test/browser_dom_nodes_select.js | took 91580ms
...
...
...

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304240917&repo=autoland&lineNumber=2418

[task 2020-05-29T10:39:42.603Z] 10:39:42     INFO - TEST-START | devtools/client/inspector/test/browser_inspector_addNode_01.js
[task 2020-05-29T10:39:43.046Z] 10:39:43     INFO - GECKO(1854) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpEZ3Z21.mozrunner/runtests_leaks_tab_pid2147.log
[task 2020-05-29T10:39:43.047Z] 10:39:43     INFO - GECKO(1854) | [2147, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-05-29T10:39:43.212Z] 10:39:43     INFO - GECKO(1854) | [Parent 1854, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp, line 1616
[task 2020-05-29T10:39:43.655Z] 10:39:43     INFO - GECKO(1854) | [Child 2147, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/checkouts/gecko/dom/ipc/ContentChild.cpp, line 1628
[task 2020-05-29T10:39:43.662Z] 10:39:43     INFO - GECKO(1854) | [Child 2147: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f3605b40c00 == 1 [pid = 2147] [id = {6c2fa4eb-ac46-4eb0-9c18-0ccf477d2dc1}]
[task 2020-05-29T10:39:43.678Z] 10:39:43     INFO - GECKO(1854) | [Child 2147: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f361b893350) [pid = 2147] [serial = 1] [outer = (nil)]
[task 2020-05-29T10:39:43.679Z] 10:39:43     INFO - GECKO(1854) | [Child 2147: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f36004ca400) [pid = 2147] [serial = 2] [outer = 0x7f361b893350]
[task 2020-05-29T10:39:43.824Z] 10:39:43     INFO - GECKO(1854) | [Child 2147: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f36004d2c00) [pid = 2147] [serial = 3] [outer = 0x7f361b893350]
[task 2020-05-29T10:39:44.005Z] 10:39:44     INFO - GECKO(1854) | [Child 1987: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f82ed8cc800 == 0 [pid = 1987] [id = {594639a2-9316-4a7b-b5d8-4c25a1c84340}] [url = about:blank]
[task 2020-05-29T10:39:44.363Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f34494b5800 == 6 [pid = 1854] [id = {de3e1132-90b2-4d5f-8608-9609b09c2cf7}]
[task 2020-05-29T10:39:44.363Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f3450ca1e30) [pid = 1854] [serial = 12] [outer = (nil)]
[task 2020-05-29T10:39:44.423Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (0x7f344ef8bc00) [pid = 1854] [serial = 13] [outer = 0x7f3450ca1e30]
[task 2020-05-29T10:39:44.505Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 14 (0x7f3451c39c00) [pid = 1854] [serial = 14] [outer = 0x7f3450ca1e30]
[task 2020-05-29T10:39:44.662Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp, line 3734
[task 2020-05-29T10:39:44.960Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f3451c3cc00 == 7 [pid = 1854] [id = {089b7865-fe1f-4b94-ad8a-00e25c157a7e}]
[task 2020-05-29T10:39:44.960Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7f344c710fb0) [pid = 1854] [serial = 15] [outer = (nil)]
[task 2020-05-29T10:39:44.961Z] 10:39:44     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7f34569b9000) [pid = 1854] [serial = 16] [outer = 0x7f344c710fb0]
[task 2020-05-29T10:39:45.395Z] 10:39:45     INFO - GECKO(1854) | [Parent 1854, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004001 (NS_ERROR_NOT_IMPLEMENTED): file /builds/worker/checkouts/gecko/dom/xul/nsXULPrototypeCache.cpp, line 235
[task 2020-05-29T10:39:45.416Z] 10:39:45     INFO - GECKO(1854) | console.error: "Store does not have a valid reducer. Make sure the argument passed to combineReducers is an object whose values are reducers."
[task 2020-05-29T10:39:46.665Z] 10:39:46     INFO - GECKO(1854) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-05-29T10:39:48.115Z] 10:39:48     INFO - GECKO(1854) | [Child 1987: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f82e74f3400) [pid = 1987] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:48.150Z] 10:39:48     INFO - GECKO(1854) | [Child 1987: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f8303693350) [pid = 1987] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.174Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7faa6f505000) [pid = 2003] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.175Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (0x7faa6f564400) [pid = 2003] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.175Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (0x7faa6f55f800) [pid = 2003] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.175Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0x7faa69ea0800) [pid = 2003] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.175Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0x7faa6f561800) [pid = 2003] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:49.235Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7faa69e80c00 == 4 [pid = 2003] [id = {4183d8d1-8110-45d1-a1c1-f8ca9abddb45}] [url = moz-extension://30bb1b49-d5f8-47dc-806b-c34a91d64819/_generated_background_page.html]
[task 2020-05-29T10:39:49.236Z] 10:39:49     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (0x7faa85293350) [pid = 2003] [serial = 1] [outer = (nil)] [url = moz-extension://30bb1b49-d5f8-47dc-806b-c34a91d64819/_generated_background_page.html]
[task 2020-05-29T10:39:51.360Z] 10:39:51     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f345262c400) [pid = 1854] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:52.191Z] 10:39:52     INFO - GECKO(1854) | [Child 1987: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f82e82b8000) [pid = 1987] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:52.192Z] 10:39:52     INFO - GECKO(1854) | [Child 1987: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f82ed994800) [pid = 1987] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:52.990Z] 10:39:52     INFO - GECKO(1854) | [Child 2093: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f92cf13d000) [pid = 2093] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:53.287Z] 10:39:53     INFO - GECKO(1854) | [Child 2003: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (0x7faa6f569000) [pid = 2003] [serial = 11] [outer = (nil)] [url = moz-extension://30bb1b49-d5f8-47dc-806b-c34a91d64819/_generated_background_page.html]
[task 2020-05-29T10:39:53.785Z] 10:39:53     INFO - GECKO(1854) | [Parent 1854: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f344ef8bc00) [pid = 1854] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:39:56.050Z] 10:39:56     INFO - GECKO(1854) | [Child 2147: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f36004ca400) [pid = 2147] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:41:13.204Z] 10:41:13     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-05-29T10:41:13.205Z] 10:41:13     INFO - Buffered messages logged at 10:39:42
[task 2020-05-29T10:41:13.206Z] 10:41:13     INFO - Entering test bound 
[task 2020-05-29T10:41:13.207Z] 10:41:13     INFO - Adding a new tab with URL: data:text/html;charset=utf-8,<h1>Add node</h1>
[task 2020-05-29T10:41:13.207Z] 10:41:13     INFO - Buffered messages logged at 10:39:43
[task 2020-05-29T10:41:13.208Z] 10:41:13     INFO - Tab added and finished loading
[task 2020-05-29T10:41:13.209Z] 10:41:13     INFO - Opening the inspector
[task 2020-05-29T10:41:13.210Z] 10:41:13     INFO - Opening the toolbox
[task 2020-05-29T10:41:13.211Z] 10:41:13     INFO - Buffered messages logged at 10:39:45
[task 2020-05-29T10:41:13.212Z] 10:41:13     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:41:13.214Z] 10:41:13     INFO - Buffered messages logged at 10:39:46
[task 2020-05-29T10:41:13.215Z] 10:41:13     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:41:13.217Z] 10:41:13     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:41:13.218Z] 10:41:13     INFO - Buffered messages finished
[task 2020-05-29T10:41:13.219Z] 10:41:13     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/test/browser_inspector_addNode_01.js | Test timed out - 
[task 2020-05-29T10:41:14.264Z] 10:41:14     INFO - GECKO(1854) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpEZ3Z21.mozrunner/runtests_leaks_tab_pid2182.log
[task 2020-05-29T10:41:14.265Z] 10:41:14     INFO - GECKO(1854) | [2182, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-05-29T10:41:14.494Z] 10:41:14     INFO - GECKO(1854) | [Child 2182, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/checkouts/gecko/dom/ipc/ContentChild.cpp, line 1628
[task 2020-05-29T10:46:02.938Z] 10:46:02     INFO - Console message: [JavaScript Error: "Unknown Collection "main/messaging-experiments"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 154}]
[task 2020-05-29T10:46:02.939Z] 10:46:02     INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:154:5
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:419:13
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - async*get@resource://services-settings/RemoteSettingsClient.jsm:356:22
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - async*updateRecipes@resource://messaging-system/lib/RemoteSettingsExperimentLoader.jsm:141:49
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - setTimer/<@resource://messaging-system/lib/RemoteSettingsExperimentLoader.jsm:188:18
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - TM_notify/</<@resource://gre/modules/UpdateTimerManager.jsm:257:36
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - ChromeUtils::IdleDispatch handler*TM_notify/<@resource://gre/modules/UpdateTimerManager.jsm:255:25
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - TM_notify@resource://gre/modules/UpdateTimerManager.jsm:290:7
[task 2020-05-29T10:46:02.940Z] 10:46:02     INFO - 
[task 2020-05-29T10:52:12.949Z] 10:52:12     INFO - Buffered messages finished
[task 2020-05-29T10:52:12.950Z] 10:52:12    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/inspector/test/browser_inspector_addNode_01.js | application timed out after 370 seconds with no output
[task 2020-05-29T10:52:12.951Z] 10:52:12    ERROR - Force-terminating active process(es).
[task 2020-05-29T10:52:12.952Z] 10:52:12     INFO - Determining child pids from psutil...
[task 2020-05-29T10:52:12.961Z] 10:52:12     INFO - [2068, 2147, 2182, 2093, 1987, 2003]
[task 2020-05-29T10:52:12.961Z] 10:52:12     INFO - ==> process 1854 launched child process 1874
...
...
...

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304240924&repo=autoland&lineNumber=1686

[task 2020-05-29T10:36:44.153Z] 10:36:44     INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_add-property-and-reselect.js
[task 2020-05-29T10:36:44.652Z] 10:36:44     INFO - GECKO(1240) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpO5XRTn.mozrunner/runtests_leaks_tab_pid1584.log
[task 2020-05-29T10:36:44.653Z] 10:36:44     INFO - GECKO(1240) | [1584, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-05-29T10:36:44.914Z] 10:36:44     INFO - GECKO(1240) | [Parent 1240, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/generic/nsFrameSelection.cpp, line 1616
[task 2020-05-29T10:36:45.184Z] 10:36:45     INFO - GECKO(1240) | [Child 1394: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7fa97fccc800 == 0 [pid = 1394] [id = {1b4151bc-48c7-47c3-be0e-10eff374fa1e}] [url = about:blank]
[task 2020-05-29T10:36:45.414Z] 10:36:45     INFO - GECKO(1240) | [Child 1584, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/checkouts/gecko/dom/ipc/ContentChild.cpp, line 1628
[task 2020-05-29T10:36:45.414Z] 10:36:45     INFO - GECKO(1240) | [Child 1584: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f42e943b000 == 1 [pid = 1584] [id = {4572fb4b-41f9-44e2-8e81-df44365f9aa2}]
[task 2020-05-29T10:36:45.430Z] 10:36:45     INFO - GECKO(1240) | [Child 1584: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f42ff193350) [pid = 1584] [serial = 1] [outer = (nil)]
[task 2020-05-29T10:36:45.430Z] 10:36:45     INFO - GECKO(1240) | [Child 1584: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f42e3dc9800) [pid = 1584] [serial = 2] [outer = 0x7f42ff193350]
[task 2020-05-29T10:36:45.571Z] 10:36:45     INFO - GECKO(1240) | [Child 1584: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f42e3dd2400) [pid = 1584] [serial = 3] [outer = 0x7f42ff193350]
[task 2020-05-29T10:36:46.265Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f8378f13c00 == 6 [pid = 1240] [id = {017bafeb-db30-4f03-8124-b8c7f15b8f39}]
[task 2020-05-29T10:36:46.265Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f8374df7d40) [pid = 1240] [serial = 12] [outer = (nil)]
[task 2020-05-29T10:36:46.366Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (0x7f837f1b7400) [pid = 1240] [serial = 13] [outer = 0x7f8374df7d40]
[task 2020-05-29T10:36:46.483Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 14 (0x7f8381288c00) [pid = 1240] [serial = 14] [outer = 0x7f8374df7d40]
[task 2020-05-29T10:36:46.625Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/base/nsContentUtils.cpp, line 3734
[task 2020-05-29T10:36:46.882Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f838e44ac00 == 7 [pid = 1240] [id = {fa5bb0c5-e857-4e9a-a5f2-71dc71f3c028}]
[task 2020-05-29T10:36:46.883Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7f8374df9870) [pid = 1240] [serial = 15] [outer = (nil)]
[task 2020-05-29T10:36:46.885Z] 10:36:46     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7f838e454800) [pid = 1240] [serial = 16] [outer = 0x7f8374df9870]
[task 2020-05-29T10:36:47.354Z] 10:36:47     INFO - GECKO(1240) | [Parent 1240, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004001 (NS_ERROR_NOT_IMPLEMENTED): file /builds/worker/checkouts/gecko/dom/xul/nsXULPrototypeCache.cpp, line 235
[task 2020-05-29T10:36:47.370Z] 10:36:47     INFO - GECKO(1240) | console.error: "Store does not have a valid reducer. Make sure the argument passed to combineReducers is an object whose values are reducers."
[task 2020-05-29T10:36:48.396Z] 10:36:48     INFO - GECKO(1240) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2020-05-29T10:36:49.308Z] 10:36:49     INFO - GECKO(1240) | [Child 1394: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7fa9798f7400) [pid = 1394] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:49.351Z] 10:36:49     INFO - GECKO(1240) | [Child 1394: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7fa995a93350) [pid = 1394] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.419Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f2c9ba05000) [pid = 1410] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.420Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (0x7f2c9ba5dc00) [pid = 1410] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.422Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (0x7f2c9ba59400) [pid = 1410] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.423Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0x7f2c96397c00) [pid = 1410] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.424Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0x7f2c9ba5b400) [pid = 1410] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:50.484Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f2c9639c800 == 4 [pid = 1410] [id = {72a1af16-f1c0-4df0-904d-41247758fe4a}] [url = moz-extension://3c86e881-d539-4764-b4d3-874d6dff87cc/_generated_background_page.html]
[task 2020-05-29T10:36:50.485Z] 10:36:50     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 9 (0x7f2cb1793520) [pid = 1410] [serial = 3] [outer = (nil)] [url = moz-extension://3c86e881-d539-4764-b4d3-874d6dff87cc/_generated_background_page.html]
[task 2020-05-29T10:36:53.051Z] 10:36:53     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f838128d800) [pid = 1240] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:53.408Z] 10:36:53     INFO - GECKO(1240) | [Child 1394: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7fa979d08000) [pid = 1394] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:53.408Z] 10:36:53     INFO - GECKO(1240) | [Child 1394: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fa97a68b400) [pid = 1394] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:54.592Z] 10:36:54     INFO - GECKO(1240) | [Child 1410: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 8 (0x7f2c96397400) [pid = 1410] [serial = 12] [outer = (nil)] [url = moz-extension://3c86e881-d539-4764-b4d3-874d6dff87cc/_generated_background_page.html]
[task 2020-05-29T10:36:54.592Z] 10:36:54     INFO - GECKO(1240) | [Child 1506: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f80c7323400) [pid = 1506] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:55.024Z] 10:36:55     INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f837f1b7400) [pid = 1240] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:36:57.790Z] 10:36:57     INFO - GECKO(1240) | [Child 1584: Main Thread]: I/
DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f42e3dc9800) [pid = 1584] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-05-29T10:38:14.903Z] 10:38:14     INFO - TEST-INFO | started process screentopng
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - TEST-INFO | screentopng: exit 0
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Buffered messages logged at 10:36:44
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Entering test bound 
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/inspector/rules/test/doc_content_stylesheet.html
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Buffered messages logged at 10:36:45
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/devtools/client/inspector/rules/test/doc_content_stylesheet.html" line: 0}]
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Tab added and finished loading
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Loading the helper frame script chrome://mochitests/content/browser/devtools/client/inspector/rules/test/doc_frame_script.js
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Opening the inspector
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Opening the toolbox
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Buffered messages logged at 10:36:47
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:15.062Z] 10:38:15     INFO - Buffered messages logged at 10:36:48
[task 2020-05-29T10:38:15.063Z] 10:38:15     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:15.063Z] 10:38:15     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 78}]
[task 2020-05-29T10:38:15.063Z] 10:38:15     INFO - Buffered messages finished
[task 2020-05-29T10:38:15.063Z] 10:38:15     INFO - TEST-UNEXPECTED-FAIL | devtools/client/inspector/rules/test/browser_rules_add-property-and-reselect.js | Test timed out - 
[task 2020-05-29T10:38:15.962Z] 10:38:15     INFO - GECKO(1240) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpO5XRTn.mozrunner/runtests_leaks_tab_pid1634.log
[task 2020-05-29T10:38:15.963Z] 10:38:15     INFO - GECKO(1240) | [1634, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp, line 243
[task 2020-05-29T10:38:16.186Z] 10:38:16     INFO - GECKO(1240) | [Child 1634, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/checkouts/gecko/dom/ipc/ContentChild.cpp, line 1628
[task 2020-05-29T10:43:04.059Z] 10:43:04     INFO - Console message: [JavaScript Error: "Unknown Collection "main/messaging-experiments"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 154}]
[task 2020-05-29T10:43:04.060Z] 10:43:04     INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:154:5
[task 2020-05-29T10:43:04.060Z] 10:43:04     INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:419:13
[task 2020-05-29T10:43:04.060Z] 10:43:04     INFO - async*get@resource://services-settings/RemoteSettingsClient.jsm:356:22
[task 2020-05-29T10:43:04.060Z] 10:43:04     INFO - async*updateRecipes@resource://messaging-system/lib/RemoteSettingsExperimentLoader.jsm:141:49
[task 2020-05-29T10:43:04.061Z] 10:43:04     INFO - setTimer/<@resource://messaging-system/lib/RemoteSettingsExperimentLoader.jsm:188:18
[task 2020-05-29T10:43:04.061Z] 10:43:04     INFO - TM_notify/</<@resource://gre/modules/UpdateTimerManager.jsm:257:36
[task 2020-05-29T10:43:04.061Z] 10:43:04     INFO - ChromeUtils::IdleDispatch handler*TM_notify/<@resource://gre/modules/UpdateTimerManager.jsm:255:25
[task 2020-05-29T10:43:04.061Z] 10:43:04     INFO - TM_notify@resource://gre/modules/UpdateTimerManager.jsm:290:7
[task 2020-05-29T10:43:04.061Z] 10:43:04     INFO - 
[task 2020-05-29T10:49:14.059Z] 10:49:14     INFO - Buffered messages finished
[task 2020-05-29T10:49:14.061Z] 10:49:14    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/inspector/rules/test/browser_rules_add-property-and-reselect.js | application timed out after 370 seconds with no output
[task 2020-05-29T10:49:14.061Z] 10:49:14    ERROR - Force-terminating active process(es).
[task 2020-05-29T10:49:14.062Z] 10:49:14     INFO - Determining child pids from psutil...
[task 2020-05-29T10:49:14.070Z] 10:49:14     INFO - [1584, 1634, 1394, 1410, 1481, 1506]
Flags: needinfo?(daisuke)

Also seeing netmonitor mochitest failures starting with the backed out changes:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=304239108&repo=autoland&lineNumber=19425

Pushed by dakatsuka.birchill@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/fa975a6a8570
Make multiple listeners can receive proper cached resources. r=ochameau
https://hg.mozilla.org/integration/autoland/rev/2e0c2a4678f7
Add test for the cache mechanism in ResourceWatcher. r=ochameau
Status: ASSIGNED → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 78
Flags: needinfo?(daisuke)
You need to log in before you can comment on or make changes to this bug.