Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=281223755&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/NleA1InSRdaPmBum8TwCHw/runs/0/artifacts/public/logs/live_backing.log

[task 2019-12-15T01:53:18.881Z] 01:53:18 INFO - TEST-START | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js
[task 2019-12-15T01:53:18.924Z] 01:53:18 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 00000236790C2000 == 7 [pid = 10316] [id = {16901fd8-35e6-4731-9d00-5d3d048b442c}]
[task 2019-12-15T01:53:18.924Z] 01:53:18 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 24 (00000236788812E0) [pid = 10316] [serial = 112] [outer = 0000000000000000]
[task 2019-12-15T01:53:18.925Z] 01:53:18 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 25 (0000023675A4C400) [pid = 10316] [serial = 113] [outer = 00000236788812E0]
[task 2019-12-15T01:53:18.944Z] 01:53:18 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 26 (00000236785D0000) [pid = 10316] [serial = 114] [outer = 00000236788812E0]
[task 2019-12-15T01:53:19.286Z] 01:53:19 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:19.286Z] 01:53:19 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:19.286Z] 01:53:19 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:19.286Z] 01:53:19 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:19.311Z] 01:53:19 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 00000145853B1000 == 2 [pid = 10656] [id = {936dc737-3dd9-48c0-93bb-3abffa478568}]
[task 2019-12-15T01:53:19.311Z] 01:53:19 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (000001458446A3E0) [pid = 10656] [serial = 50] [outer = 0000000000000000]
[task 2019-12-15T01:53:19.311Z] 01:53:19 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (00000145844A6800) [pid = 10656] [serial = 51] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:19.370Z] 01:53:19 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (0000014584D34C00) [pid = 10656] [serial = 52] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:19.728Z] 01:53:19 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (00000290A1E69000) [pid = 9988] [serial = 47] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Ahall%C3%B8j]
[task 2019-12-15T01:53:19.746Z] 01:53:19 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 000002909B37A800 == 0 [pid = 9988] [id = {5c2ff0c6-2b31-400f-b558-d6ab2a9e9ab5}] [url = about:blank]
[task 2019-12-15T01:53:20.659Z] 01:53:20 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 00000236790B9800 == 6 [pid = 10316] [id = {2e8bdc88-f497-43a2-99c6-f554eddb17f5}] [url = about:blank]
[task 2019-12-15T01:53:20.975Z] 01:53:20 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:21.370Z] 01:53:21 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (0000014584D39C00) [pid = 10656] [serial = 47] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:21.370Z] 01:53:21 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 00000145853AF000 == 1 [pid = 10656] [id = {4e2e797c-cfd2-4351-9386-ff3ff5562e7d}] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Atest-page]
[task 2019-12-15T01:53:22.078Z] 01:53:22 INFO - GECKO(5180) | [Child 4520: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (00000219C8C78980) [pid = 4520] [serial = 66] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.442Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 25 (0000023675973800) [pid = 10316] [serial = 104] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.442Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 24 (0000023678880020) [pid = 10316] [serial = 106] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.442Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 23 (0000023672DD6C00) [pid = 10316] [serial = 107] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.442Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (0000023678881E20) [pid = 10316] [serial = 103] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.624Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:22.968Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (0000023675A4C000) [pid = 10316] [serial = 105] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.970Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (0000023675054C00) [pid = 10316] [serial = 110] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:22.970Z] 01:53:22 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0000023675053000) [pid = 10316] [serial = 108] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:23.947Z] 01:53:23 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (000002909F7187A0) [pid = 9988] [serial = 48] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:25.535Z] 01:53:25 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0000014584D38C00) [pid = 10656] [serial = 48] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page]
[task 2019-12-15T01:53:25.535Z] 01:53:25 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (00000145844A6800) [pid = 10656] [serial = 51] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:25.615Z] 01:53:25 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (000001458446A7A0) [pid = 10656] [serial = 45] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Atest-page]
[task 2019-12-15T01:53:26.064Z] 01:53:26 INFO - GECKO(5180) | [Child 10656, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:26.073Z] 01:53:26 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0000014584D33C00) [pid = 10656] [serial = 53] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:26.111Z] 01:53:26 INFO - GECKO(5180) | [Child 4520: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (00000219C95D4000) [pid = 4520] [serial = 68] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:26.111Z] 01:53:26 INFO - GECKO(5180) | [Child 4520: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (00000219C43EB400) [pid = 4520] [serial = 70] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:26.650Z] 01:53:26 INFO - GECKO(5180) | [Child 10656, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:26.654Z] 01:53:26 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (00000145853DDC00) [pid = 10656] [serial = 54] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:28.017Z] 01:53:28 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (00000290A1E6F800) [pid = 9988] [serial = 50] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:29.372Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0000023674D4C000 == 7 [pid = 10316] [id = {b8e2506c-75d3-4b9d-9870-a9947f9cf874}]
[task 2019-12-15T01:53:29.372Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0000023678880020) [pid = 10316] [serial = 115] [outer = 0000000000000000]
[task 2019-12-15T01:53:29.374Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (00000236693AC000) [pid = 10316] [serial = 116] [outer = 0000023678880020]
[task 2019-12-15T01:53:29.395Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (00000236743A2000) [pid = 10316] [serial = 117] [outer = 0000023678880020]
[task 2019-12-15T01:53:29.708Z] 01:53:29 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0000014586C5EC00) [pid = 10656] [serial = 49] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Atest-page]
[task 2019-12-15T01:53:29.738Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:29.738Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:29.738Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:29.738Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:29.777Z] 01:53:29 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 000002909B379800 == 1 [pid = 9988] [id = {b5d4ce6f-c640-4499-a0d2-8b0626e06e4d}]
[task 2019-12-15T01:53:29.777Z] 01:53:29 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (000002909F718200) [pid = 9988] [serial = 51] [outer = 0000000000000000]
[task 2019-12-15T01:53:29.777Z] 01:53:29 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (000002909B3F7000) [pid = 9988] [serial = 52] [outer = 000002909F718200]
[task 2019-12-15T01:53:29.836Z] 01:53:29 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (000002909F7BAC00) [pid = 9988] [serial = 53] [outer = 000002909F718200]
[task 2019-12-15T01:53:29.915Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (00000236788803E0) [pid = 10316] [serial = 109] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:29.915Z] 01:53:29 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (00000236752EAC00) [pid = 10316] [serial = 111] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:30.176Z] 01:53:30 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:31.699Z] 01:53:31 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:33.835Z] 01:53:33 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 00000145853B1000 == 0 [pid = 10656] [id = {936dc737-3dd9-48c0-93bb-3abffa478568}] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:33.835Z] 01:53:33 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0000014584D33C00) [pid = 10656] [serial = 53] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page]
[task 2019-12-15T01:53:33.835Z] 01:53:33 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0000014584D34C00) [pid = 10656] [serial = 52] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:33.945Z] 01:53:33 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (000001458446A3E0) [pid = 10656] [serial = 50] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:34.942Z] 01:53:34 INFO - GECKO(5180) | [Child 9988, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:34.944Z] 01:53:34 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (00000290A06B2C00) [pid = 9988] [serial = 54] [outer = 000002909F718200]
[task 2019-12-15T01:53:35.296Z] 01:53:35 INFO - GECKO(5180) | [Child 9988, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:35.301Z] 01:53:35 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (00000290A1E6EC00) [pid = 9988] [serial = 55] [outer = 000002909F718200]
[task 2019-12-15T01:53:37.822Z] 01:53:37 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0000023674D52000 == 8 [pid = 10316] [id = {b5a396a2-b4e7-4c0f-9bf9-9f1b668c7e9c}]
[task 2019-12-15T01:53:37.822Z] 01:53:37 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (00000236788803E0) [pid = 10316] [serial = 118] [outer = 0000000000000000]
[task 2019-12-15T01:53:37.822Z] 01:53:37 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (0000023672DC8800) [pid = 10316] [serial = 119] [outer = 00000236788803E0]
[task 2019-12-15T01:53:37.841Z] 01:53:37 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 23 (00000236749D3800) [pid = 10316] [serial = 120] [outer = 00000236788803E0]
[task 2019-12-15T01:53:37.961Z] 01:53:37 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (00000145853DDC00) [pid = 10656] [serial = 54] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:38.010Z] 01:53:38 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 000002909B379800 == 0 [pid = 9988] [id = {b5d4ce6f-c640-4499-a0d2-8b0626e06e4d}] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:38.148Z] 01:53:38 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:38.148Z] 01:53:38 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:38.148Z] 01:53:38 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:38.148Z] 01:53:38 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:38.178Z] 01:53:38 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 000002909B37A000 == 1 [pid = 9988] [id = {70c83ec7-4b35-4b1d-9a75-41a78514f671}]
[task 2019-12-15T01:53:38.178Z] 01:53:38 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (000002909F7187A0) [pid = 9988] [serial = 56] [outer = 0000000000000000]
[task 2019-12-15T01:53:38.178Z] 01:53:38 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (000002909F708000) [pid = 9988] [serial = 57] [outer = 000002909F7187A0]
[task 2019-12-15T01:53:38.257Z] 01:53:38 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (00000290A06B3400) [pid = 9988] [serial = 58] [outer = 000002909F7187A0]
[task 2019-12-15T01:53:38.559Z] 01:53:38 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:39.890Z] 01:53:39 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:42.145Z] 01:53:42 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (000002909B3F7000) [pid = 9988] [serial = 52] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:42.145Z] 01:53:42 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (00000290A06B2C00) [pid = 9988] [serial = 54] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page]
[task 2019-12-15T01:53:43.322Z] 01:53:43 INFO - GECKO(5180) | [Child 9988, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:43.324Z] 01:53:43 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (00000290A1E65400) [pid = 9988] [serial = 59] [outer = 000002909F7187A0]
[task 2019-12-15T01:53:43.697Z] 01:53:43 INFO - GECKO(5180) | [Child 9988, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:43.707Z] 01:53:43 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (00000290A2E11400) [pid = 9988] [serial = 60] [outer = 000002909F7187A0]
[task 2019-12-15T01:53:44.862Z] 01:53:44 INFO - TEST-INFO | started process screenshot
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - TEST-INFO | screenshot: exit 0
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - Buffered messages logged at 01:53:18
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - Entering test bound
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - CDP server started
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - Buffered messages logged at 01:53:26
[task 2019-12-15T01:53:44.952Z] 01:53:44 INFO - CDP client instantiated
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id should be a string -
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Two scripts should have different ids -
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - Navigating to data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello
[task 2019-12-15T01:53:44.953Z] 01:53:44 INFO - Buffered messages logged at 01:53:27
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - Runtime.executionContextCreated: default
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected number of contexts got created -
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Got default context -
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Got default context -
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Get context with empty name -
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - Buffered messages logged at 01:53:29
[task 2019-12-15T01:53:44.954Z] 01:53:44 INFO - CDP client closed
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - CDP server stopped
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - Leaving test bound
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - Entering test bound
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - CDP server started
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - Buffered messages logged at 01:53:34
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - CDP client instantiated
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - Buffered messages logged at 01:53:35
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id should be a string -
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2019-12-15T01:53:44.955Z] 01:53:44 INFO - Buffered messages logged at 01:53:36
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - TEST-PASS | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Two scripts should have different ids -
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - Buffered messages logged at 01:53:37
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - CDP client closed
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - CDP server stopped
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - Leaving test bound
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - Entering test bound
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - CDP server started
[task 2019-12-15T01:53:44.956Z] 01:53:44 INFO - Buffered messages logged at 01:53:43
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - CDP client instantiated
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - Navigating to data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - Runtime.executionContextCreated: default
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - url about:blank
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - Runtime.executionContextCreated: default
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - Runtime.executionContextCreated: isolated
[task 2019-12-15T01:53:44.957Z] 01:53:44 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - Runtime.executionContextCreated: isolated
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - Navigating to data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3ENext
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - Buffered messages finished
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected number of contexts got created - Got 0, expected 2
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - Stack trace:
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochikit/content/browser-test.js:test_is:1320
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:checkIsolatedContextAfterLoad:120
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:addWithIsolatedWorldAndNavigate:61
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochitests/content/browser/remote/test/browser/head.js:this.add_task/<:40
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1062
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1097
[task 2019-12-15T01:53:44.958Z] 01:53:44 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:925
[task 2019-12-15T01:53:44.959Z] 01:53:44 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:808
[task 2019-12-15T01:53:44.977Z] 01:53:44 INFO - CDP client closed
[task 2019-12-15T01:53:46.174Z] 01:53:46 INFO - CDP server stopped
[task 2019-12-15T01:53:46.265Z] 01:53:46 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-15T01:53:46.265Z] 01:53:46 INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Uncaught exception - at chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:121 - TypeError: contexts[0] is undefined
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - Stack trace:
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - checkIsolatedContextAfterLoad@chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:121:3
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - asyncaddWithIsolatedWorldAndNavigate@chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:61:26
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - asyncthis.add_task/<@chrome://mochitests/content/browser/remote/test/browser/head.js:40:15
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1062:34
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - asyncTester_execTest@chrome://mochikit/content/browser-test.js:1097:11
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:925:14
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:808:67
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - Leaving test bound
[task 2019-12-15T01:53:46.266Z] 01:53:46 INFO - Entering test bound
[task 2019-12-15T01:53:46.305Z] 01:53:46 INFO - CDP server started
[task 2019-12-15T01:53:46.305Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 000002367B2CC000 == 9 [pid = 10316] [id = {87bf32e8-eefe-4c11-b483-0b0b4e9873a9}]
[task 2019-12-15T01:53:46.305Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 24 (00000236788816A0) [pid = 10316] [serial = 121] [outer = 0000000000000000]
[task 2019-12-15T01:53:46.305Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 25 (00000236749CC800) [pid = 10316] [serial = 122] [outer = 00000236788816A0]
[task 2019-12-15T01:53:46.323Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 26 (0000023675054000) [pid = 10316] [serial = 123] [outer = 00000236788816A0]
[task 2019-12-15T01:53:46.325Z] 01:53:46 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (000002909F7BAC00) [pid = 9988] [serial = 53] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:46.325Z] 01:53:46 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (000002909F708000) [pid = 9988] [serial = 57] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:46.600Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:46.600Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:46.600Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 45
[task 2019-12-15T01:53:46.600Z] 01:53:46 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file z:/build/build/src/extensions/permissions/nsPermission.cpp, line 57
[task 2019-12-15T01:53:46.625Z] 01:53:46 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 00000145853AC800 == 1 [pid = 10656] [id = {601e7185-2b58-4295-b8c8-0e1f3f817427}]
[task 2019-12-15T01:53:46.625Z] 01:53:46 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (000001458446A3E0) [pid = 10656] [serial = 55] [outer = 0000000000000000]
[task 2019-12-15T01:53:46.625Z] 01:53:46 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (000001458440AC00) [pid = 10656] [serial = 56] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:46.684Z] 01:53:46 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0000014584D31800) [pid = 10656] [serial = 57] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:47.056Z] 01:53:47 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:48.480Z] 01:53:48 INFO - GECKO(5180) | [Parent 10316, Main Thread] WARNING: NS_ENSURE_TRUE(aURI) failed: file z:/build/build/src/netwerk/dns/nsEffectiveTLDService.cpp, line 176
[task 2019-12-15T01:53:50.501Z] 01:53:50 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 000002909B37A000 == 0 [pid = 9988] [id = {70c83ec7-4b35-4b1d-9a75-41a78514f671}] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3ENext]
[task 2019-12-15T01:53:50.501Z] 01:53:50 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (00000290A06B3400) [pid = 9988] [serial = 58] [outer = 0000000000000000] [url = about:blank]
[task 2019-12-15T01:53:50.600Z] 01:53:50 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (000002909F718200) [pid = 9988] [serial = 51] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:50.600Z] 01:53:50 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (000002909F7187A0) [pid = 9988] [serial = 56] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3ENext]
[task 2019-12-15T01:53:51.577Z] 01:53:51 INFO - CDP client instantiated
[task 2019-12-15T01:53:51.602Z] 01:53:51 INFO - Navigating to data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-15T01:53:51.760Z] 01:53:51 INFO - GECKO(5180) | [Child 10656, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file z:/build/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-15T01:53:51.765Z] 01:53:51 INFO - GECKO(5180) | [Child 10656: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0000014584D3A400) [pid = 10656] [serial = 58] [outer = 000001458446A3E0]
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected number of contexts got created - Got 0, expected 2
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - Stack trace:
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochikit/content/browser-test.js:test_is:1320
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:checkIsolatedContextAfterLoad:120
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:addWithIsolatedWorldNavigateTwice:74
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochitests/content/browser/remote/test/browser/head.js:this.add_task/<:40
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1062
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1097
[task 2019-12-15T01:53:53.328Z] 01:53:53 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:925
[task 2019-12-15T01:53:53.329Z] 01:53:53 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:808
[task 2019-12-15T01:53:53.449Z] 01:53:53 INFO - CDP client closed
[task 2019-12-15T01:53:54.628Z] 01:53:54 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (00000290A2E11400) [pid = 9988] [serial = 60] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3ENext]
[task 2019-12-15T01:53:54.630Z] 01:53:54 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (00000290A1E65400) [pid = 9988] [serial = 59] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page]
[task 2019-12-15T01:53:54.630Z] 01:53:54 INFO - GECKO(5180) | [Child 9988: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (00000290A1E6EC00) [pid = 9988] [serial = 55] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello]
[task 2019-12-15T01:53:54.751Z] 01:53:54 INFO - CDP server stopped
[task 2019-12-15T01:53:54.813Z] 01:53:54 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-15T01:53:54.813Z] 01:53:54 INFO - TEST-UNEXPECTED-FAIL | remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Uncaught exception - at chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:121 - TypeError: contexts[0] is undefined
[task 2019-12-15T01:53:54.813Z] 01:53:54 INFO - Stack trace:
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - checkIsolatedContextAfterLoad@chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:121:3
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - asyncaddWithIsolatedWorldNavigateTwice@chrome://mochitests/content/browser/remote/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:74:9
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - asyncthis.add_task/<@chrome://mochitests/content/browser/remote/test/browser/head.js:40:15
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - AsyncTester_execTest/<@chrome://mochikit/content/browser-test.js:1062:34
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - asyncTester_execTest@chrome://mochikit/content/browser-test.js:1097:11
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:925:14
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:808:67
[task 2019-12-15T01:53:54.814Z] 01:53:54 INFO - Leaving test bound
...

This seem to be a regression from Bug 1597879

(In reply to Noemi Erli[:noemi_erli] from comment #2)

This seem to be a regression from Bug 1597879

Not sure why you are needinfo'ing me but not the author of the patch. Forwarding to Maja

Similarly to Bug 1602686, I think is partly due to Page.navigate returning too early (Bug 1603776). However, in this case I believe that bug contributes to a race between the call to Page.addScriptToEvaluateOnNewDocument (see testWorld) and the internal [script-loaded]https://searchfox.org/mozilla-central/rev/c61720a7d0c094d772059f9d6a7844eb7619f107/remote/domains/ContextObserver.jsm#83-86) event that is supposed to happen after a page load.

The test fails when addScriptToEvaluateOnNewDocument happens to run before the script-loaded for the previous page load. The race is likely made worse by the fact the we spin the event loop before emitting script-loaded (see https://phabricator.services.mozilla.com/D55334#inline-335891)

Log excerpt: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=281601714&repo=try&lineNumber=6992-7010

[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - Navigating to data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - Runtime.executionContextCreated: default
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	url about:blank
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	name 
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	id 1
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - Runtime.executionContextCreated: default
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	name 
[task 2019-12-17T19:37:39.823Z] 19:37:39     INFO - 	id 2
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - Runtime.executionContextCreated: isolated
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	name testWorld
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	id 3
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - Runtime.executionContextCreated: isolated
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	name testWorldb
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - 	id 4
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - Buffered messages finished
[task 2019-12-17T19:37:39.824Z] 19:37:39     INFO - TEST-UNEXPECTED-FAIL | remo

Maja, could we also have the workaround for the problem with navigate in place here?

There haven't been any failures since the 18th so I'll hold off for now.

Maybe this failure was a side-effect from the other test? Waiting for the page load there might have helped here too. Lets see how this week goes, and if no more failure happens we can mark it as fixed next week.

There are 22 total failures in the last 7 days.

debug: linux1804-64, linux1804-64-qr, windows10-64, windows7-32

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

This waits on work for bug 1603776 Maja is currently working on. Hopefully we will have some improvements later this week.

Note that the increase of failures in the last week are related to new linux1804-64-qr jobs, which failed 22 times on their own already!

There are 26 failures associated to this bug in the last 7 days. These are occurring on linux1804-64-qr and linux1804-64 debug builds.

Waiting for updates from bug 1603776 for this.

As it looks like the landed patch from bug 1599257 helped a lot. Since its landing the test failed only two times. Lets observe the failures over the next days, but as it looks like it doesn't need special attention anymore.

Failed for me here I Think : https://treeherder.mozilla.org/#/jobs?repo=try&revision=cf4fbc5a16236363458b0e16f44912a53f79dc3a&selectedTaskRun=WIK6JjZ9SkO4htRScH5HXQ-0

Note that tests on Linux always fail in addWithIsolatedWorldNavigateTwice, and tests on Windows in addTwoScriptsWithIsolatedWorld. Also there aren't any failures yet for Mac.

I do some refactoring of the test on bug 1593226. Maybe it will already help here.

Looks like a too short timeout for the events. Might be fixed with the patch on bug 1638196.

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=338790539&repo=autoland&lineNumber=39396

[task 2021-05-05T08:50:15.377Z] 08:50:15 INFO - TEST-START | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js
[task 2021-05-05T08:50:15.388Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7feb0412ac00 == 8 [pid = 3923] [id = 151]
[task 2021-05-05T08:50:15.389Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 46 (7feb04936740) [pid = 3923] [serial = 424] [outer = 0]
[task 2021-05-05T08:50:15.391Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 47 (7feb0412d400) [pid = 3923] [serial = 425] [outer = 7feb04936740]
[task 2021-05-05T08:50:15.400Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 48 (7feb041aec00) [pid = 3923] [serial = 426] [outer = 7feb04936740]
[task 2021-05-05T08:50:15.476Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:46
[task 2021-05-05T08:50:15.477Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:58
[task 2021-05-05T08:50:15.478Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, nullptr) failed with result 0x804B000A (NS_ERROR_MALFORMED_URI): file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:46
[task 2021-05-05T08:50:15.478Z] 08:50:15 INFO - GECKO(3923) | [Parent 3923, Main Thread] WARNING: NS_ENSURE_TRUE(principal) failed: file /builds/worker/checkouts/gecko/extensions/permissions/Permission.cpp:58
[task 2021-05-05T08:50:15.489Z] 08:50:15 INFO - GECKO(3923) | [Child 4096: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f13bed28800 == 2 [pid = 4096] [id = 125]
[task 2021-05-05T08:50:15.489Z] 08:50:15 INFO - GECKO(3923) | [Child 4096: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 7 (7f13c10c1040) [pid = 4096] [serial = 382] [outer = 0]
[task 2021-05-05T08:50:15.496Z] 08:50:15 INFO - GECKO(3923) | [Child 4096: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (7f13bed2a000) [pid = 4096] [serial = 383] [outer = 7f13c10c1040]

[task 2021-05-05T08:50:23.174Z] 08:50:23 INFO - TEST-INFO | started process screentopng
[task 2021-05-05T08:50:23.441Z] 08:50:23 INFO - TEST-INFO | screentopng: exit 0
[task 2021-05-05T08:50:23.441Z] 08:50:23 INFO - Buffered messages logged at 08:50:15
[task 2021-05-05T08:50:23.441Z] 08:50:23 INFO - Entering test bound uniqueIdForAddedScripts
[task 2021-05-05T08:50:23.441Z] 08:50:23 INFO - Remote agent started
[task 2021-05-05T08:50:23.442Z] 08:50:23 INFO - Buffered messages logged at 08:50:17
[task 2021-05-05T08:50:23.442Z] 08:50:23 INFO - CDP client instantiated
[task 2021-05-05T08:50:23.442Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id should be a string -
[task 2021-05-05T08:50:23.443Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2021-05-05T08:50:23.443Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2021-05-05T08:50:23.448Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Two scripts should have different ids -
[task 2021-05-05T08:50:23.449Z] 08:50:23 INFO - Runtime.executionContextCreated: default
[task 2021-05-05T08:50:23.449Z] 08:50:23 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0A%3Cp%3EHello
[task 2021-05-05T08:50:23.449Z] 08:50:23 INFO - Buffered messages logged at 08:50:18
[task 2021-05-05T08:50:23.450Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected number of contexts got created -
[task 2021-05-05T08:50:23.451Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected frame id found -
[task 2021-05-05T08:50:23.452Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Got default context -
[task 2021-05-05T08:50:23.452Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Got default context -
[task 2021-05-05T08:50:23.453Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Get context with empty name -
[task 2021-05-05T08:50:23.454Z] 08:50:23 INFO - CDP client closed
[task 2021-05-05T08:50:23.455Z] 08:50:23 INFO - Leaving test bound uniqueIdForAddedScripts
[task 2021-05-05T08:50:23.456Z] 08:50:23 INFO - Entering test bound addScriptAfterNavigation
[task 2021-05-05T08:50:23.456Z] 08:50:23 INFO - Buffered messages logged at 08:50:19
[task 2021-05-05T08:50:23.459Z] 08:50:23 INFO - CDP client instantiated
[task 2021-05-05T08:50:23.460Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id should be a string -
[task 2021-05-05T08:50:23.461Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2021-05-05T08:50:23.463Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Script id is non-empty -
[task 2021-05-05T08:50:23.464Z] 08:50:23 INFO - TEST-PASS | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Two scripts should have different ids -
[task 2021-05-05T08:50:23.465Z] 08:50:23 INFO - CDP client closed
[task 2021-05-05T08:50:23.466Z] 08:50:23 INFO - Leaving test bound addScriptAfterNavigation
[task 2021-05-05T08:50:23.467Z] 08:50:23 INFO - Entering test bound addWithIsolatedWorldAndNavigate
[task 2021-05-05T08:50:23.471Z] 08:50:23 INFO - Buffered messages logged at 08:50:20
[task 2021-05-05T08:50:23.472Z] 08:50:23 INFO - CDP client instantiated
[task 2021-05-05T08:50:23.474Z] 08:50:23 INFO - Buffered messages logged at 08:50:21
[task 2021-05-05T08:50:23.475Z] 08:50:23 INFO - Runtime.executionContextCreated: default
[task 2021-05-05T08:50:23.475Z] 08:50:23 INFO - url about:blank
[task 2021-05-05T08:50:23.476Z] 08:50:23 INFO - Runtime.executionContextCreated: default
[task 2021-05-05T08:50:23.476Z] 08:50:23 INFO - url data:text/html;charset=utf-8,%3C!doctype%20html%3E%0A%3Cmeta%20charset%3Dutf-8%3E%0Adefault-test-page
[task 2021-05-05T08:50:23.477Z] 08:50:23 INFO - Buffered messages finished
[task 2021-05-05T08:50:23.480Z] 08:50:23 INFO - TEST-UNEXPECTED-FAIL | remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js | Expected number of contexts got created - Got +0, expected 2
[task 2021-05-05T08:50:23.480Z] 08:50:23 INFO - Stack trace:
[task 2021-05-05T08:50:23.480Z] 08:50:23 INFO - chrome://mochikit/content/browser-test.js:test_is:1369
[task 2021-05-05T08:50:23.480Z] 08:50:23 INFO - chrome://mochitests/content/browser/remote/cdp/test/browser/page/browser_scriptToEvaluateOnNewDocument.js:checkIsolatedContextAfterLoad:158
[task 2021-05-05T08:50:23.488Z] 08:50:23 INFO - CDP client closed

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=342632528&repo=autoland&lineNumber=38968

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=346524600&repo=mozilla-central&lineNumber=40416

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=350803812&repo=mozilla-central&lineNumber=39233

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=384325373&repo=autoland