Open Bug 1584007 Opened 5 months ago Updated 5 months ago

ClientHandles attaching to ClientSources may race

Categories

(Core :: DOM: Service Workers, defect, P2)

defect

Tracking

()

People

(Reporter: perry, Assigned: perry)

References

Details

Attachments

(1 file)

Essentially, when a ClientHandle's ClientHandleParent calls ClientManagerService::FindSource, it's unknown whether the corresponding ClientSource's ClientSourceParent has already registered with the ClientManagerService and been destroyed or if it can be expected to register in the future. This can cause a timeout in the case the ClientSourceParent has already been destroyed (the ClientHandleParent will wait forever to connect).

Example of this is bug 1583659.


Proposed fix:

When a ClientHandle's ClientHandleParent tries to find its ClientSource's ClientSourceParent (on the IPDL background thread), we want to guarantee:

  • If the ClientManagerService has the ClientSourceParent, connect the Client{Handle,Source}Parents
  • Else if there's a "waiting ClientHandles queue", the ClientSource's ClientSourceParent will, at some point in the future, register with the ClientManagerService, so enqueue the current ClientHandleParent
  • Else the ClientSource must have been destroyed and removed its ClientSourceParent from the ClientManagerService, so propagate deletion/failure to the ClientHandle

To ensure those conditions:

  • Such a "waiting ClientHandles queue" must be created or a ClientSourceParent must register with the ClientManagerService before any ClientHandles are created (note that the queue and handles may be created on separate threads)
    • ClientHandles require ClientInfos, and ClientInfos are created by either ClientSources or ClientManager::CreateInfo
      • ClientSources immediately call SendPClientSourceConstructor, which is the fastest way (will win any race) to the ClientManagerService (directly Child Main Thread -> Parent IPDL background Thread) (this relies on ordering between different IPC channels)
        • Eliminates the need for a way to represent a "future ClientSource"
      • Calls to ClientManager::CreateInfo should guarantee that they register the "future ClientSource" before anything can create a ClientHandle with the returned ClientInfo
        • Should also abort the "future ClientSource" (e.g. the ClientSource that would be associated with this ClientInfo on a redirect) when it's known that it'll never exist
Duplicate of this bug: 1583659

This patch introduces the concept of a "future ClientSource" to the
ClientManagerService. A "future ClientSource" is registered/removed
from the ClientManagerService by
ClientManager::{Register,Forget}FutureClientSource and is required
when a ClientInfo is initially created without a backing ClientSource.

As a result, the ClientManagerService can distinguish between a
ClientSourceParent* that has yet to register itself with the
ClientManagerService and a ClientSourceParent* that has already
both registered and removed itself from the ClientManagerService.

Pushed by pjiang@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/daecd36223c9
avoid race in ClientManagerService::FindSource r=asuth

Backed out changeset daecd36223c9 (Bug 1584007) for ClientManagerService.cpp failures

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&fromchange=daecd36223c955d8f2dfcada32034c11af62641e&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64%2Fdebug-mochitest-browser-chrome-fis-e10s&tochange=d227b30b9940b2b3aeefdaf85c84af8e3f0e7863&selectedJob=269399276

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

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

[task 2019-10-02T11:13:48.094Z] 11:13:48 INFO - TEST-OK | netwerk/test/browser/browser_test_io_activity.js | took 2591ms
[task 2019-10-02T11:13:48.109Z] 11:13:48 INFO - GECKO(12162) | ++DOCSHELL 0x7f8b53fb1000 == 1 [pid = 12749] [id = {d6df8e8e-aca9-434b-9e4f-15e4721e64c8}]
[task 2019-10-02T11:13:48.151Z] 11:13:48 INFO - checking window state
[task 2019-10-02T11:13:48.232Z] 11:13:48 INFO - GECKO(12162) | [Parent 12162, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/dom/base/nsFrameLoader.cpp, line 673
[task 2019-10-02T11:13:48.232Z] 11:13:48 INFO - GECKO(12162) | ++DOMWINDOW == 21 (0x7fc3736e1c00) [pid = 12162] [serial = 23] [outer = 0x7fc37dfe7200]
[task 2019-10-02T11:13:48.276Z] 11:13:48 INFO - GECKO(12162) | ++DOMWINDOW == 1 (0x7f8b53f08f20) [pid = 12749] [serial = 1] [outer = (nil)]
[task 2019-10-02T11:13:48.279Z] 11:13:48 INFO - GECKO(12162) | ++DOMWINDOW == 2 (0x7f8b53f30800) [pid = 12749] [serial = 2] [outer = 0x7f8b53f08f20]
[task 2019-10-02T11:13:48.282Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7febe5fb3800 == 0 [pid = 12728] [id = {ec45d058-3d07-4fc0-a408-2033b9aa0427}] [url = https://example.com/browser/netwerk/test/browser/ioactivity.html]
[task 2019-10-02T11:13:48.330Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7fd5628b1000 == 0 [pid = 12461] [id = {3fbbedac-6afd-40a1-a311-fcd5a6aa4741}] [url = about:blank]
[task 2019-10-02T11:13:48.346Z] 11:13:48 INFO - GECKO(12162) | ++DOMWINDOW == 22 (0x7fc3751c1000) [pid = 12162] [serial = 24] [outer = 0x7fc37dfe7200]
[task 2019-10-02T11:13:48.506Z] 11:13:48 INFO - GECKO(12162) | --DOMWINDOW == 2 (0x7febe70b0f20) [pid = 12728] [serial = 1] [outer = (nil)] [url = https://example.com/browser/netwerk/test/browser/ioactivity.html]
[task 2019-10-02T11:13:48.507Z] 11:13:48 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7febe5f07000) [pid = 12728] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:48.507Z] 11:13:48 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7febe5f6d800) [pid = 12728] [serial = 3] [outer = (nil)] [url = https://example.com/browser/netwerk/test/browser/ioactivity.html]
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mAllocCount: 7547
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mFreeCount: 7547
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mShareCount: 5227
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mAdoptCount: 323
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => mAdoptFreeCount: 327
[task 2019-10-02T11:13:48.725Z] 11:13:48 INFO - GECKO(12162) | => Process ID: 12728, Thread ID: 140651605231424
[task 2019-10-02T11:13:48.761Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7f4b2f6b6800 == 0 [pid = 12660] [id = {3866282e-bfc1-493c-b155-7c6b4aa6701d}] [url = about:blank]
[task 2019-10-02T11:13:48.781Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7f4ef22b4800 == 0 [pid = 12609] [id = {7bd787ca-e13b-498d-954a-ec2a4c62a95b}] [url = about:blank]
[task 2019-10-02T11:13:48.781Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7f797fab1000 == 0 [pid = 12539] [id = {d884a4aa-10de-4154-8aca-7a1e1ea4eb0f}] [url = about:blank]
[task 2019-10-02T11:13:48.797Z] 11:13:48 INFO - GECKO(12162) | --DOCSHELL 0x7fabf74b4800 == 0 [pid = 12707] [id = {6192978e-fd75-4549-8242-99a44c7a3f6d}] [url = about:blank]
[task 2019-10-02T11:13:48.898Z] 11:13:48 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7fd562830800) [pid = 12461] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:48.898Z] 11:13:48 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7fd56281bf20) [pid = 12461] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:49.489Z] 11:13:49 INFO - GECKO(12162) | --DOCSHELL 0x7fc37d4b9000 == 7 [pid = 12162] [id = {84e59833-3e22-4ade-a5d3-961425712f5f}] [url = about:cache-entry?storage=disk&context=&eid=&uri=https://example.com/browser/netwerk/test/browser/dummy.html]
[task 2019-10-02T11:13:49.490Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 21 (0x7fc373982800) [pid = 12162] [serial = 18] [outer = (nil)] [url = about:cache?storage=disk&context=]
[task 2019-10-02T11:13:49.490Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 20 (0x7fc378d8ac00) [pid = 12162] [serial = 17] [outer = (nil)] [url = about:cache]
[task 2019-10-02T11:13:49.491Z] 11:13:49 INFO - GECKO(12162) | --DOCSHELL 0x7fc3736b9800 == 6 [pid = 12162] [id = {cdcda278-047a-46b7-9799-9a14385268a1}] [url = about:license]
[task 2019-10-02T11:13:49.974Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 19 (0x7fc3760bc400) [pid = 12162] [serial = 21] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:49.976Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 18 (0x7fc378e0dc00) [pid = 12162] [serial = 16] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:49.976Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 17 (0x7fc378da1a60) [pid = 12162] [serial = 15] [outer = (nil)] [url = about:cache-entry?storage=disk&context=&eid=&uri=https://example.com/browser/netwerk/test/browser/dummy.html]
[task 2019-10-02T11:13:49.977Z] 11:13:49 INFO - GECKO(12162) | --DOMWINDOW == 16 (0x7fc37a850c40) [pid = 12162] [serial = 20] [outer = (nil)] [url = about:license]
[task 2019-10-02T11:13:50.519Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7f4b2f637c00) [pid = 12660] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.520Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7f4b30699f20) [pid = 12660] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.536Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7fabf7435c00) [pid = 12707] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.537Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7fabf83daf20) [pid = 12707] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.538Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7f797fa30c00) [pid = 12539] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.538Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7f4ef2235c00) [pid = 12609] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.539Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7f797fa18f20) [pid = 12539] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:50.542Z] 11:13:50 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7f4ef31daf20) [pid = 12609] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:51.033Z] 11:13:51 INFO - GECKO(12162) | --DOCSHELL 0x7fe96bce4000 == 0 [pid = 12235] [id = {5dfa93fe-6ead-4b9c-8dcc-bb7dca44b521}] [url = about:newtab]
[task 2019-10-02T11:13:51.034Z] 11:13:51 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7fe96c7854c0) [pid = 12235] [serial = 4] [outer = (nil)] [url = about:newtab]
[task 2019-10-02T11:13:51.035Z] 11:13:51 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7fe96bcc6c00) [pid = 12235] [serial = 6] [outer = (nil)] [url = about:newtab]
[task 2019-10-02T11:13:51.496Z] 11:13:51 INFO - GECKO(12162) | --DOMWINDOW == 15 (0x7fc37398e000) [pid = 12162] [serial = 19] [outer = (nil)] [url = about:cache-entry?storage=disk&context=&eid=&uri=https://example.com/browser/netwerk/test/browser/dummy.html]
[task 2019-10-02T11:13:51.496Z] 11:13:51 INFO - GECKO(12162) | --DOMWINDOW == 14 (0x7fc37579dc00) [pid = 12162] [serial = 22] [outer = (nil)] [url = about:license]
[task 2019-10-02T11:13:51.652Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12461
[task 2019-10-02T11:13:51.808Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12749
[task 2019-10-02T11:13:51.810Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12609
[task 2019-10-02T11:13:51.891Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12539
[task 2019-10-02T11:13:51.947Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12707
[task 2019-10-02T11:13:51.947Z] 11:13:51 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12660
[task 2019-10-02T11:13:52.084Z] 11:13:52 INFO - GECKO(12162) | --DOMWINDOW == 13 (0x7fc37d97f800) [pid = 12162] [serial = 9] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:52.280Z] 11:13:52 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12212
[task 2019-10-02T11:13:52.288Z] 11:13:52 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12235
[task 2019-10-02T11:13:52.625Z] 11:13:52 INFO - GECKO(12162) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp4jQwK6.mozrunner/runtests_leaks_tab_pid12775.log
[task 2019-10-02T11:13:52.747Z] 11:13:52 INFO - GECKO(12162) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-10-02T11:13:54.532Z] 11:13:54 INFO - GECKO(12162) | --DOMWINDOW == 12 (0x7fc3736e1c00) [pid = 12162] [serial = 23] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:54.916Z] 11:13:54 INFO - GECKO(12162) | Completed ShutdownLeaks collections in process 12162
[task 2019-10-02T11:13:54.916Z] 11:13:54 INFO - TEST-START | Shutdown
[task 2019-10-02T11:13:54.917Z] 11:13:54 INFO - Browser Chrome Test Summary
[task 2019-10-02T11:13:54.921Z] 11:13:54 INFO - Passed: 41
[task 2019-10-02T11:13:54.922Z] 11:13:54 INFO - Failed: 0
[task 2019-10-02T11:13:54.923Z] 11:13:54 INFO - Todo: 2
[task 2019-10-02T11:13:54.923Z] 11:13:54 INFO - Mode: e10s
[task 2019-10-02T11:13:54.933Z] 11:13:54 INFO - *** End BrowserChrome Test Results ***
[task 2019-10-02T11:13:55.235Z] 11:13:55 INFO - GECKO(12162) | [Parent 12162, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 919
[task 2019-10-02T11:13:55.235Z] 11:13:55 INFO - GECKO(12162) | [Parent 12162, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 882
[task 2019-10-02T11:13:55.235Z] 11:13:55 INFO - GECKO(12162) | [Parent 12162, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsApplicationCacheService.cpp, line 159
[task 2019-10-02T11:13:55.311Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7f2ba121f000 == 2 [pid = 12212] [id = {eb1ed07b-5546-4147-be7d-26fc0817fc47}] [url = moz-extension://4332d2c3-df23-4d4a-aa5e-0002a06e883d/_generated_background_page.html]
[task 2019-10-02T11:13:55.311Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7f2ba09b5800 == 1 [pid = 12212] [id = {0d06fcd8-f8d1-48c6-b4d0-cf92c98acb94}] [url = moz-extension://ad455756-86ae-420b-9f3b-de3c74fcaa68/_generated_background_page.html]
[task 2019-10-02T11:13:55.311Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7f2bba285000 == 0 [pid = 12212] [id = {aab3c833-a537-41df-b20d-4f1ac9d72680}] [url = moz-extension://ab5a72a1-fb00-43c1-b6cb-94664734a896/_generated_background_page.html]
[task 2019-10-02T11:13:55.372Z] 11:13:55 INFO - GECKO(12162) | [2019-10-02T11:13:55Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2019-10-02T11:13:55.372Z] 11:13:55 INFO - GECKO(12162) | [2019-10-02T11:13:55Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2019-10-02T11:13:55.396Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 5 (0x7f2ba18d96a0) [pid = 12212] [serial = 3] [outer = (nil)] [url = moz-extension://4332d2c3-df23-4d4a-aa5e-0002a06e883d/_generated_background_page.html]
[task 2019-10-02T11:13:55.397Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 4 (0x7f2ba18d94c0) [pid = 12212] [serial = 1] [outer = (nil)] [url = moz-extension://ad455756-86ae-420b-9f3b-de3c74fcaa68/_generated_background_page.html]
[task 2019-10-02T11:13:55.398Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 3 (0x7f2ba18d83e0) [pid = 12212] [serial = 5] [outer = (nil)] [url = moz-extension://ab5a72a1-fb00-43c1-b6cb-94664734a896/_generated_background_page.html]
[task 2019-10-02T11:13:55.399Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 2 (0x7f2ba18ab400) [pid = 12212] [serial = 10] [outer = (nil)] [url = moz-extension://4332d2c3-df23-4d4a-aa5e-0002a06e883d/_generated_background_page.html]
[task 2019-10-02T11:13:55.400Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7f2ba1999c00) [pid = 12212] [serial = 11] [outer = (nil)] [url = moz-extension://ab5a72a1-fb00-43c1-b6cb-94664734a896/_generated_background_page.html]
[task 2019-10-02T11:13:55.401Z] 11:13:55 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7f2ba1843800) [pid = 12212] [serial = 9] [outer = (nil)] [url = moz-extension://ad455756-86ae-420b-9f3b-de3c74fcaa68/_generated_background_page.html]
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mAllocCount: 16015
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mFreeCount: 16015
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mShareCount: 9279
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mAdoptCount: 472
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => mAdoptFreeCount: 496
[task 2019-10-02T11:13:55.438Z] 11:13:55 INFO - GECKO(12162) | => Process ID: 12212, Thread ID: 139825807005504
[task 2019-10-02T11:13:55.554Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.562Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc376020800 == 5 [pid = 12162] [id = {b36d3ddf-d0eb-43ef-976d-55a033e9562d}] [url = chrome://mochikit/content/browser-harness.xul]
[task 2019-10-02T11:13:55.563Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc3812ce800 == 4 [pid = 12162] [id = {65188128-3706-4d79-b266-b44a864c1565}] [url = chrome://browser/content/browser.xhtml]
[task 2019-10-02T11:13:55.563Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc37e578800 == 3 [pid = 12162] [id = {eac19531-7195-4aab-b447-b579af20a820}] [url = about:blank]
[task 2019-10-02T11:13:55.565Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc37ddc1000 == 2 [pid = 12162] [id = {d7406fef-c0a1-4c85-a568-8d323d560b0b}] [url = about:blank]
[task 2019-10-02T11:13:55.566Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc37d75b000 == 1 [pid = 12162] [id = {d625839f-bde3-4dc8-a08f-cec195ed88d1}] [url = chrome://extensions/content/dummy.xul]
[task 2019-10-02T11:13:55.586Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7fc37af3b000 == 0 [pid = 12162] [id = {55ac4e08-53aa-4dec-8edd-8af8f1aed8da}] [url = resource://gre-resources/hiddenWindow.html]
[task 2019-10-02T11:13:55.622Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.623Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.631Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.631Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.641Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.658Z] 11:13:55 INFO - GECKO(12162) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-10-02T11:13:55.855Z] 11:13:55 INFO - GECKO(12162) | --DOCSHELL 0x7f8b53fb1000 == 0 [pid = 12749] [id = {d6df8e8e-aca9-434b-9e4f-15e4721e64c8}] [url = about:blank]
[task 2019-10-02T11:13:55.911Z] 11:13:55 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:55.911Z] 11:13:55 INFO - GECKO(12162) | => mAllocCount: 5421
[task 2019-10-02T11:13:55.912Z] 11:13:55 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:55.914Z] 11:13:55 INFO - GECKO(12162) | => mFreeCount: 5421
[task 2019-10-02T11:13:55.914Z] 11:13:55 INFO - GECKO(12162) | => mShareCount: 2865
[task 2019-10-02T11:13:55.915Z] 11:13:55 INFO - GECKO(12162) | => mAdoptCount: 69
[task 2019-10-02T11:13:55.916Z] 11:13:55 INFO - GECKO(12162) | => mAdoptFreeCount: 69
[task 2019-10-02T11:13:55.916Z] 11:13:55 INFO - GECKO(12162) | => Process ID: 12775, Thread ID: 140271415674688
[task 2019-10-02T11:13:55.966Z] 11:13:55 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:55.968Z] 11:13:55 INFO - GECKO(12162) | => mAllocCount: 7198
[task 2019-10-02T11:13:55.968Z] 11:13:55 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:55.968Z] 11:13:55 INFO - GECKO(12162) | => mFreeCount: 7198
[task 2019-10-02T11:13:55.969Z] 11:13:55 INFO - GECKO(12162) | => mShareCount: 5053
[task 2019-10-02T11:13:55.969Z] 11:13:55 INFO - GECKO(12162) | => mAdoptCount: 319
[task 2019-10-02T11:13:55.970Z] 11:13:55 INFO - GECKO(12162) | => mAdoptFreeCount: 319
[task 2019-10-02T11:13:55.971Z] 11:13:55 INFO - GECKO(12162) | => Process ID: 12660, Thread ID: 139961347606336
[task 2019-10-02T11:13:55.971Z] 11:13:55 INFO - GECKO(12162) | nsStringStats
...
[task 2019-10-02T11:13:56.042Z] 11:13:56 INFO - GECKO(12162) | => Process ID: 12461, Thread ID: 140554910095168
[task 2019-10-02T11:13:56.042Z] 11:13:56 INFO - GECKO(12162) | --DOMWINDOW == 1 (0x7f8b53f08f20) [pid = 12749] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:56.043Z] 11:13:56 INFO - GECKO(12162) | --DOMWINDOW == 0 (0x7f8b53f30800) [pid = 12749] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-10-02T11:13:56.071Z] 11:13:56 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:56.072Z] 11:13:56 INFO - GECKO(12162) | => mAllocCount: 13557
[task 2019-10-02T11:13:56.073Z] 11:13:56 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:56.073Z] 11:13:56 INFO - GECKO(12162) | => mFreeCount: 13557
[task 2019-10-02T11:13:56.073Z] 11:13:56 INFO - GECKO(12162) | => mShareCount: 18373
[task 2019-10-02T11:13:56.074Z] 11:13:56 INFO - GECKO(12162) | => mAdoptCount: 516
[task 2019-10-02T11:13:56.075Z] 11:13:56 INFO - GECKO(12162) | => mAdoptFreeCount: 520
[task 2019-10-02T11:13:56.075Z] 11:13:56 INFO - GECKO(12162) | => Process ID: 12235, Thread ID: 140640958658368
[task 2019-10-02T11:13:56.091Z] 11:13:56 INFO - GECKO(12162) | nsStringStats
[task 2019-10-02T11:13:56.091Z] 11:13:56 INFO - GECKO(12162) | => mAllocCount: 7095
[task 2019-10-02T11:13:56.091Z] 11:13:56 INFO - GECKO(12162) | => mReallocCount: 0
[task 2019-10-02T11:13:56.092Z] 11:13:56 INFO - GECKO(12162) | => mFreeCount: 7095
[task 2019-10-02T11:13:56.092Z] 11:13:56 INFO - GECKO(12162) | => mShareCount: 4743
[task 2019-10-02T11:13:56.093Z] 11:13:56 INFO - GECKO(12162) | => mAdoptCount: 404
[task 2019-10-02T11:13:56.093Z] 11:13:56 INFO - GECKO(12162) | => mAdoptFreeCount: 404
[task 2019-10-02T11:13:56.094Z] 11:13:56 INFO - GECKO(12162) | => Process ID: 12749, Thread ID: 140236838688576
[task 2019-10-02T11:13:56.215Z] 11:13:56 INFO - GECKO(12162) | 1570014836210 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2019-10-02T11:13:56.216Z] 11:13:56 INFO - GECKO(12162) | 1570014836211 Marionette INFO Stopped listening on port 2828
[task 2019-10-02T11:13:56.216Z] 11:13:56 INFO - GECKO(12162) | 1570014836211 Marionette DEBUG Remote service is inactive
[task 2019-10-02T11:13:56.217Z] 11:13:56 INFO - GECKO(12162) | Assertion failure: mSourceTable.count() == 0, at /builds/worker/workspace/build/src/dom/clients/manager/ClientManagerService.cpp:141
[task 2019-10-02T11:13:56.220Z] 11:13:56 INFO - GECKO(12162) | #01: mozilla::dom::ClientManagerService::Release() [dom/clients/manager/ClientManagerService.h:82]
[task 2019-10-02T11:13:56.220Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.221Z] 11:13:56 INFO - GECKO(12162) | #02: mozilla::MozPromise<bool, nsresult, true>::ThenValue<mozilla::dom::ClientManagerService::ClientManagerService()::$_17>::DoResolveOrRejectInternal(mozilla::MozPromise<bool, nsresult, true>::ResolveOrRejectValue&) [xpcom/threads/MozPromise.h:801]
[task 2019-10-02T11:13:56.221Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.221Z] 11:13:56 INFO - GECKO(12162) | #03: mozilla::MozPromise<bool, nsresult, true>::ThenValueBase::ResolveOrRejectRunnable::Run() [xpcom/threads/MozPromise.h:403]
[task 2019-10-02T11:13:56.221Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.222Z] 11:13:56 INFO - GECKO(12162) | #04: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1225]
[task 2019-10-02T11:13:56.222Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.222Z] 11:13:56 INFO - GECKO(12162) | #05: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:486]
[task 2019-10-02T11:13:56.223Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.225Z] 11:13:56 INFO - GECKO(12162) | #06: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:303]
[task 2019-10-02T11:13:56.225Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.226Z] 11:13:56 INFO - GECKO(12162) | #07: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:315]
[task 2019-10-02T11:13:56.226Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.226Z] 11:13:56 INFO - GECKO(12162) | #08: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
[task 2019-10-02T11:13:56.226Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.230Z] 11:13:56 INFO - GECKO(12162) | #09: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:460]
[task 2019-10-02T11:13:56.230Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | #10: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:201]
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | #11: libpthread.so.0 + 0x76ba
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | #12: libc.so.6 + 0x10741d
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO -
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | #13: ??? (???:???)
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | ExceptionHandler::GenerateDump cloned child 12799
[task 2019-10-02T11:13:56.275Z] 11:13:56 INFO - GECKO(12162) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-10-02T11:13:56.276Z] 11:13:56 INFO - GECKO(12162) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-10-02T11:13:56.392Z] 11:13:56 INFO - TEST-INFO | Main app process: exit 11
[task 2019-10-02T11:13:56.392Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_about_cache.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.393Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_cookie_sync_across_tabs.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.394Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_cross_process_redirect.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.394Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_post_file.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.395Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_resource_navigation.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.395Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_test_favicon.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.396Z] 11:13:56 INFO - TEST-INFO | netwerk/test/browser/browser_test_io_activity.js | This test created 1 hidden docshell(s)
[task 2019-10-02T11:13:56.397Z] 11:13:56 INFO - Buffered messages finished
[task 2019-10-02T11:13:56.397Z] 11:13:56 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 11
[task 2019-10-02T11:13:56.398Z] 11:13:56 INFO - runtests.py | Application ran for: 0:00:31.709222
[task 2019-10-02T11:13:56.399Z] 11:13:56 INFO - zombiecheck | Reading PID log: /tmp/tmpt6FhkEpidlog
[task 2019-10-02T11:13:56.399Z] 11:13:56 INFO - ==> process 12162 launched child process 12180
...

Flags: needinfo?(perry)
Flags: needinfo?(perry)
You need to log in before you can comment on or make changes to this bug.