New occurrence: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=232904344&repo=autoland&lineNumber=23919

13:43:19 INFO - TEST-START | testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py TestNavigate.test_set_location_through_execute_script
13:43:19 INFO - 1552138999785 Marionette DEBUG Closed connection 18
13:43:19 INFO - 1552138999786 Marionette DEBUG Accepted connection 19 from 127.0.0.1:51225
13:43:19 INFO - 1552138999788 Marionette DEBUG 19 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
13:43:19 INFO - 1552138999791 Marionette TRACE [30064771073] Frame script loaded
13:43:19 INFO - 1552138999792 Marionette TRACE [30064771073] Frame script registered
13:43:19 INFO - 1552138999796 Marionette DEBUG 19 <- [1,1,null,{"sessionId":"a37b1cb9-41f2-450b-8a22-e478a4b056f3","capabilities":{"browserName":"firefox","browserVersion":"67.0a ... p\tmputxygt.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
13:43:19 INFO - 1552138999798 Marionette DEBUG 19 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
13:43:19 INFO - 1552138999799 Marionette DEBUG 19 <- [1,2,null,{"value":null}]
13:43:19 INFO - 1552138999802 Marionette DEBUG 19 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
13:43:19 INFO - 1552138999803 Marionette DEBUG 19 <- [1,3,null,{"value":null}]
13:43:19 INFO - 1552138999804 Marionette DEBUG 19 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
13:43:19 INFO - 1552138999805 Marionette DEBUG 19 <- [1,4,null,{"value":null}]
13:43:19 INFO - 1552138999807 Marionette DEBUG 19 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
13:43:19 INFO - 1552138999807 Marionette DEBUG 19 <- [1,5,null,{"value":"1"}]
13:43:19 INFO - 1552138999809 Marionette DEBUG 19 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
13:43:19 INFO - 1552138999809 Marionette DEBUG 19 <- [1,6,null,["1"]]
13:43:19 INFO - 1552138999811 Marionette DEBUG 19 -> [0,7,"WebDriver:GetWindowHandle",{}]
13:43:19 INFO - 1552138999811 Marionette DEBUG 19 <- [1,7,null,{"value":"30064771073"}]
13:43:19 INFO - 1552138999813 Marionette DEBUG 19 -> [0,8,"WebDriver:GetWindowHandles",{}]
13:43:19 INFO - 1552138999814 Marionette DEBUG 19 <- [1,8,null,["30064771073"]]
13:43:19 INFO - 1552138999816 Marionette DEBUG 19 -> [0,9,"WebDriver:GetWindowHandles",{}]
13:43:19 INFO - 1552138999817 Marionette DEBUG 19 <- [1,9,null,["30064771073"]]
13:43:19 INFO - 1552138999818 Marionette DEBUG 19 -> [0,10,"WebDriver:NewWindow",{"type":"tab","focus":false}]
13:43:19 INFO - ++DOCSHELL 000002B42BC2B800 == 16 [pid = 10600] [id = {628056fe-e841-42b3-81bd-0b4e73d37a22}]
13:43:19 INFO - ++DOMWINDOW == 50 (000002B4294E5E20) [pid = 10600] [serial = 50] [outer = 0000000000000000]
13:43:19 INFO - 1552138999826 Marionette TRACE Received DOM event TabOpen for [object XULElement]
13:43:19 INFO - ++DOMWINDOW == 51 (000002B42BC4CC00) [pid = 10600] [serial = 51] [outer = 000002B4294E5E20]
13:43:19 INFO - 1552138999832 Marionette TRACE [8589934642] Frame script loaded
13:43:19 INFO - 1552138999873 Marionette TRACE [8589934642] Frame script registered
13:43:19 INFO - ++DOMWINDOW == 52 (000002B42BF17400) [pid = 10600] [serial = 52] [outer = 000002B4294E5E20]
13:43:19 INFO - 1552138999888 Marionette DEBUG 19 <- [1,10,null,{"handle":"8589934642","type":"tab"}]
13:43:19 INFO - 1552138999902 Marionette DEBUG 19 -> [0,11,"WebDriver:GetWindowHandles",{}]
13:43:19 INFO - 1552138999902 Marionette DEBUG 19 <- [1,11,null,["30064771073","8589934642"]]
13:43:19 INFO - 1552138999904 Marionette DEBUG 19 -> [0,12,"WebDriver:GetWindowHandles",{}]
13:43:19 INFO - 1552138999904 Marionette DEBUG 19 <- [1,12,null,["30064771073","8589934642"]]
13:43:19 INFO - 1552138999906 Marionette DEBUG 19 -> [0,13,"WebDriver:SwitchToWindow",{"focus":true,"name":"8589934642"}]
13:43:19 INFO - 1552138999919 Marionette DEBUG 19 <- [1,13,null,{"value":null}]
13:43:19 INFO - 1552138999935 Marionette DEBUG 19 -> [0,14,"WebDriver:GetTimeouts",{}]
13:43:19 INFO - 1552138999936 Marionette DEBUG 19 <- [1,14,null,{"implicit":0,"pageLoad":300000,"script":30000}]
13:43:19 INFO - 1552138999938 Marionette DEBUG 19 -> [0,15,"WebDriver:ExecuteScript",{"script":"return window.history.length;","newSandbox":true,"args":[],"filename":"Z:\task_15 ... te\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py","sandbox":"default","line":74}]
13:43:19 INFO - 1552138999943 Marionette DEBUG 19 <- [1,15,null,{"value":1}]
13:43:19 INFO - 1552138999955 Marionette DEBUG 19 -> [0,16,"WebDriver:Navigate",{"url":"http://127.0.0.1:50268/navigation_pushstate.html"}]
13:43:19 INFO - 1552138999962 Marionette TRACE [8589934642] Received DOM event beforeunload for about:blank
13:43:19 INFO - [Parent 5224, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/netwerk/url-classifier/UrlClassifierCommon.cpp, line 114
13:43:20 INFO - 1552139000412 Marionette TRACE [8589934642] Received DOM event pagehide for about:blank
13:43:20 INFO - 1552139000413 Marionette TRACE [8589934642] Received DOM event unload for about:blank
13:43:20 INFO - ++DOMWINDOW == 53 (000002B42BF1BC00) [pid = 10600] [serial = 53] [outer = 000002B4294E5E20]
13:43:20 INFO - 1552139000440 Marionette TRACE [8589934642] Received DOM event DOMContentLoaded for http://127.0.0.1:50268/navigation_pushstate.html
13:43:20 INFO - 1552139000459 Marionette TRACE [8589934642] Received DOM event pageshow for http://127.0.0.1:50268/navigation_pushstate.html
13:43:20 INFO - 1552139000473 Marionette DEBUG 19 <- [1,16,null,{"value":null}]
13:43:20 INFO - 1552139000516 Marionette DEBUG 19 -> [0,17,"WebDriver:ExecuteScript",{"script":"window.location.href = arguments[0];","newSandbox":true,"args":["http://127.0.0.1: ... onette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py","sandbox":null,"line":126}]
13:43:20 INFO - 1552139000529 Marionette DEBUG 19 <- [1,17,null,{"value":null}]
13:43:20 INFO - 1552139000532 Marionette DEBUG 19 -> [0,18,"WebDriver:GetTimeouts",{}]
13:43:20 INFO - 1552139000532 Marionette DEBUG 19 <- [1,18,null,{"implicit":0,"pageLoad":300000,"script":30000}]
13:43:20 INFO - [Child 10600, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file z:/build/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 1997
13:43:20 INFO - 1552139000537 Marionette DEBUG 19 -> [0,19,"WebDriver:FindElement",{"using":"id","value":"testh1"}]
13:43:20 INFO - ++DOCSHELL 000001DA3E54B800 == 1 [pid = 10932] [id = {5b98dea8-1c76-41e9-a1d0-063f708f718c}]
13:43:20 INFO - ++DOMWINDOW == 1 (000001DA444DA020) [pid = 10932] [serial = 1] [outer = 0000000000000000]
13:43:20 INFO - ++DOMWINDOW == 2 (000001DA44457400) [pid = 10932] [serial = 2] [outer = 000001DA444DA020]
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - --DOMWINDOW == 19 (000002070C3EC200) [pid = 5224] [serial = 18] [outer = 0000000000000000] [url = about:robots]
13:43:20 INFO - --DOMWINDOW == 18 (000002070D7E06A0) [pid = 5224] [serial = 15] [outer = 0000000000000000] [url = about:robots]
13:43:20 INFO - --DOMWINDOW == 17 (000002070D7FCE20) [pid = 5224] [serial = 12] [outer = 0000000000000000] [url = about:robots]
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, *this) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 472
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(mStatus, mStatus) failed with result 0x804B000A: file z:/build/build/src/obj-firefox/dist/include\nsIURIMutator.h, line 622
13:43:20 INFO - 1552139000642 Marionette TRACE [32212254721] Frame script loaded
13:43:20 INFO - 1552139000655 Marionette TRACE [32212254721] Frame script registered
13:43:20 INFO - ++DOMWINDOW == 3 (000001DA45D68C00) [pid = 10932] [serial = 3] [outer = 000001DA444DA020]
13:43:20 INFO - [Parent 5224, Main Thread] WARNING: '!parent', file z:/build/build/src/netwerk/ipc/NeckoParent.cpp, line 954
13:43:23 INFO - --DOMWINDOW == 14 (000001E04938D000) [pid = 4064] [serial = 2] [outer = 0000000000000000] [url = about:blank]
13:43:23 INFO - --DOMWINDOW == 13 (000001E04AF94400) [pid = 4064] [serial = 4] [outer = 0000000000000000] [url = about:blank]
13:43:23 INFO - --DOMWINDOW == 12 (000001E04AF96C00) [pid = 4064] [serial = 6] [outer = 0000000000000000] [url = about:blank]
13:43:23 INFO - --DOMWINDOW == 11 (000001E04AF99C00) [pid = 4064] [serial = 10] [outer = 0000000000000000] [url = about:blank]
13:43:23 INFO - --DOMWINDOW == 10 (000001E04AF98400) [pid = 4064] [serial = 8] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 52 (000002B42C506C00) [pid = 10600] [serial = 42] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 51 (000002B42C502800) [pid = 10600] [serial = 39] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 50 (000002B42C025400) [pid = 10600] [serial = 36] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 49 (000002B42C021400) [pid = 10600] [serial = 33] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 48 (000002B42C01B800) [pid = 10600] [serial = 29] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 47 (000002B42BF21C00) [pid = 10600] [serial = 25] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 46 (000002B42BF1F000) [pid = 10600] [serial = 22] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E#Foo]
13:43:24 INFO - --DOMWINDOW == 45 (000002B42BF1A400) [pid = 10600] [serial = 20] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 44 (000002B42BF17C00) [pid = 10600] [serial = 17] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 43 (000002B42BC4D000) [pid = 10600] [serial = 14] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 42 (000002B42BC49000) [pid = 10600] [serial = 11] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 41 (000002B42BC45400) [pid = 10600] [serial = 8] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 40 (000002B42BC41800) [pid = 10600] [serial = 5] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 39 (000002B429469400) [pid = 10600] [serial = 2] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 38 (000002B42C01D800) [pid = 10600] [serial = 30] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 37 (000002B42BF1C800) [pid = 10600] [serial = 21] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 36 (000002B42BF23C00) [pid = 10600] [serial = 26] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BC2C000 == 15 [pid = 10600] [id = {d4d0822e-555b-4205-95da-f711e9f4e931}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCDE800 == 14 [pid = 10600] [id = {8746a762-7e84-4b65-9809-edba88bb0538}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCF6800 == 13 [pid = 10600] [id = {2d9587a4-208d-4369-a798-20f06ed72b73}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCEB000 == 12 [pid = 10600] [id = {5a7807c3-9090-47c0-bf90-4a4369d02332}] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E#foo]
13:43:24 INFO - --DOCSHELL 000002B42C097800 == 11 [pid = 10600] [id = {049b138a-9e99-4dba-9240-640857ac22a4}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCF2000 == 10 [pid = 10600] [id = {d0ed443f-03ae-4d2a-b020-3d8e265d4bad}] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E#foo]
13:43:24 INFO - --DOCSHELL 000002B42BC27000 == 9 [pid = 10600] [id = {39fad83f-2b09-44b2-a54b-015de0f476d8}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCDA000 == 8 [pid = 10600] [id = {4940c7a2-095d-45b7-912b-6c38e2d34d85}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BC23000 == 7 [pid = 10600] [id = {65366807-e7a4-4801-9764-6339a3a4e3cd}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42C09C000 == 6 [pid = 10600] [id = {7c2621f3-4f63-44a8-8b33-0e0444525ec3}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42BCE2000 == 5 [pid = 10600] [id = {fbf61105-2fb6-4e82-8a10-e5973e5be6ab}] [url = data:text/html;charset=utf-8,%3cp%20id%3dfoo%3e#foo]
13:43:24 INFO - --DOCSHELL 000002B423B4B000 == 4 [pid = 10600] [id = {92037ec0-f672-464d-a7a3-4ea72ad685bd}] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 35 (000002B4294E47A0) [pid = 10600] [serial = 10] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 34 (000002B4294E4B60) [pid = 10600] [serial = 16] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 33 (000002B4294E52E0) [pid = 10600] [serial = 32] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 32 (000002B4294E4F20) [pid = 10600] [serial = 24] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E#foo]
13:43:24 INFO - --DOMWINDOW == 31 (000002B4294E54C0) [pid = 10600] [serial = 35] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 30 (000002B4294E5100) [pid = 10600] [serial = 28] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E]
13:43:24 INFO - --DOMWINDOW == 29 (000002B4294E45C0) [pid = 10600] [serial = 7] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 28 (000002B4294E4980) [pid = 10600] [serial = 13] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 27 (000002B4294E4200) [pid = 10600] [serial = 4] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 26 (000002B4294E56A0) [pid = 10600] [serial = 38] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 25 (000002B4294E4D40) [pid = 10600] [serial = 19] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3cp%20id%3dfoo%3e#foo]
13:43:24 INFO - --DOMWINDOW == 24 (000002B4294E4020) [pid = 10600] [serial = 1] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 23 (000002B4294E5880) [pid = 10600] [serial = 41] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOMWINDOW == 22 (000002B4294E5A60) [pid = 10600] [serial = 44] [outer = 0000000000000000] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B42C0A0800 == 3 [pid = 10600] [id = {b1f1038f-5ead-43ee-8b31-667de242564f}] [url = about:blank]
13:43:24 INFO - --DOCSHELL 000002B423B3D000 == 2 [pid = 10600] [id = {68053ed3-2b4d-4aae-ae97-3bdcc3de085d}] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 16 (000002070DBBB000) [pid = 5224] [serial = 19] [outer = 0000000000000000] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 15 (000002070DF33400) [pid = 5224] [serial = 20] [outer = 0000000000000000] [url = about:robots]
13:43:26 INFO - --DOMWINDOW == 14 (000002070DF3C000) [pid = 5224] [serial = 16] [outer = 0000000000000000] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 13 (000002070DF42400) [pid = 5224] [serial = 17] [outer = 0000000000000000] [url = about:robots]
13:43:26 INFO - --DOMWINDOW == 12 (000002071375E800) [pid = 5224] [serial = 13] [outer = 0000000000000000] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 11 (000002070FBE1400) [pid = 5224] [serial = 9] [outer = 0000000000000000] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 10 (0000020713765400) [pid = 5224] [serial = 14] [outer = 0000000000000000] [url = about:robots]
13:43:26 INFO - --DOMWINDOW == 9 (000002070FBDF800) [pid = 5224] [serial = 8] [outer = 0000000000000000] [url = about:blank]
13:43:26 INFO - --DOMWINDOW == 8 (000002070ED1EC00) [pid = 5224] [serial = 6] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOCSHELL 000002070E33D800 == 6 [pid = 5224] [id = {e299582d-dd95-43cd-8a9e-608511af2db5}] [url = about:robots]
13:43:28 INFO - --DOCSHELL 0000020709411000 == 5 [pid = 5224] [id = {9d23a385-832e-43bd-a26d-4f5319b1b54c}] [url = about:robots]
13:43:28 INFO - --DOCSHELL 000002070E1B3000 == 4 [pid = 5224] [id = {0d84d0f9-d0dd-47f8-bb21-261806e89ec3}] [url = about:robots]
13:43:28 INFO - --DOMWINDOW == 21 (000002B42B26C800) [pid = 10600] [serial = 45] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 20 (000002B42B271000) [pid = 10600] [serial = 48] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 19 (000002B42BC4CC00) [pid = 10600] [serial = 51] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 18 (000002B42BF15400) [pid = 10600] [serial = 15] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 17 (000002B42BC41C00) [pid = 10600] [serial = 46] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 16 (000002B42C023400) [pid = 10600] [serial = 34] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 15 (000002B42BF18C00) [pid = 10600] [serial = 18] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 14 (000002B42BC47800) [pid = 10600] [serial = 9] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 13 (000002B42BC43C00) [pid = 10600] [serial = 6] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 12 (000002B42B271C00) [pid = 10600] [serial = 3] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 11 (000002B42C508000) [pid = 10600] [serial = 43] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 10 (000002B42BC4A800) [pid = 10600] [serial = 12] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 9 (000002B42C504400) [pid = 10600] [serial = 40] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 8 (000002B42C027000) [pid = 10600] [serial = 37] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 7 (000002B42BF17400) [pid = 10600] [serial = 52] [outer = 0000000000000000] [url = about:blank]
13:43:28 INFO - --DOMWINDOW == 6 (000002B42C01A800) [pid = 10600] [serial = 27] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E#foo]
13:43:28 INFO - --DOMWINDOW == 5 (000002B42BF21800) [pid = 10600] [serial = 23] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3cp%20id%3dfoo%3e#foo]
13:43:28 INFO - --DOMWINDOW == 4 (000002B42C01F000) [pid = 10600] [serial = 31] [outer = 0000000000000000] [url = data:text/html;charset=utf-8,%3Cp%20id%3Dfoo%3E]
13:43:34 INFO - --DOCSHELL 000002B42B24B800 == 1 [pid = 10600] [id = {0fccc89c-4f4a-4852-b77b-1cd833754a49}] [url = about:blank]
13:43:34 INFO - --DOCSHELL 000002B42BC2B800 == 0 [pid = 10600] [id = {628056fe-e841-42b3-81bd-0b4e73d37a22}] [url = http://127.0.0.1:50268/navigation_pushstate.html]
13:43:34 INFO - --DOMWINDOW == 3 (000002B4294E5C40) [pid = 10600] [serial = 47] [outer = 0000000000000000] [url = about:blank]
13:43:34 INFO - --DOMWINDOW == 2 (000002B4294E5E20) [pid = 10600] [serial = 50] [outer = 0000000000000000] [url = http://127.0.0.1:50268/navigation_pushstate.html]
13:43:35 INFO - --DOMWINDOW == 2 (000001DA44457400) [pid = 10932] [serial = 2] [outer = 0000000000000000] [url = about:blank]
13:43:36 INFO - [Parent 5224, StreamTrans #35] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 371
13:43:36 INFO - [Parent 5224, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 993
13:43:38 INFO - --DOMWINDOW == 2 (00000293F1C57400) [pid = 7468] [serial = 2] [outer = 0000000000000000] [url = about:blank]
13:43:38 INFO - --DOMWINDOW == 1 (000002B42BF1BC00) [pid = 10600] [serial = 53] [outer = 0000000000000000] [url = http://127.0.0.1:50268/navigation_pushstate.html]
13:43:38 INFO - --DOMWINDOW == 0 (000002B42BC47000) [pid = 10600] [serial = 49] [outer = 0000000000000000] [url = about:blank]
13:44:07 INFO - [Parent 5224, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/netwerk/url-classifier/UrlClassifierCommon.cpp, line 114
13:44:07 INFO - [Parent 5224, Main Thread] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/netwerk/url-classifier/AsyncUrlChannelClassifier.cpp, line 757
13:45:08 INFO - [Parent 5224, Lazy Idle] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils.cpp, line 1346
13:46:08 INFO - [Parent 5224, Main Thread] WARNING: Suboptimal indexes for the SQL statement 0x2070f42b5e0 (http://mzl.la/1FuID0j).: file z:/build/build/src/storage/mozStoragePrivateHelpers.cpp, line 108
13:47:08 INFO - [Parent 5224, Lazy Idle] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils.cpp, line 1346
13:49:20 INFO - 1552139360580 Marionette DEBUG Closed connection 19
13:50:31 ERROR - TEST-UNEXPECTED-ERROR | testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py TestNavigate.test_set_location_through_execute_script | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)
13:50:31 INFO - Traceback (most recent call last):
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 159, in run
13:50:31 INFO - testMethod()
13:50:31 INFO - File "Z:\task_1552135541\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 130, in test_set_location_through_execute_script
13:50:31 INFO - message="Target element 'testh1' has not been found")
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\wait.py", line 129, in until
13:50:31 INFO - rv = condition(self.marionette)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\expected.py", line 48, in call
13:50:31 INFO - return _find(marionette, self.locator)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\expected.py", line 311, in _find
13:50:31 INFO - el = func(marionette)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\expected.py", line 45, in <lambda>
13:50:31 INFO - self.locator = lambda m: m.find_element(*args)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1865, in find_element
13:50:31 INFO - body, key="value")
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\decorators.py", line 36, in _
13:50:31 INFO - m._handle_socket_failure()
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\marionette.py", line 849, in _handle_socket_failure
13:50:31 INFO - reraise(IOError, message.format(returncode=returncode, reason=val), tb)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _
13:50:31 INFO - return func(*args, **kwargs)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\marionette.py", line 761, in _send_message
13:50:31 INFO - msg = self.client.request(name, params)
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\transport.py", line 273, in request
13:50:31 INFO - return self.receive()
13:50:31 INFO - File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\transport.py", line 183, in receive
13:50:31 INFO - raise socket.timeout("Connection timed out after {}s".format(self.socket_timeout))
13:50:31 INFO - TEST-INFO took 431911ms
13:50:31 INFO - test_end for testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py TestNavigate.test_set_location_through_execute_script logged while not in progress. Logged with data: {"status": "ERROR", "extra": {"class_name": "test_navigation.TestNavigate", "method_name": "test_set_location_through_execute_script"}, "expected": "PASS", "test": "testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py TestNavigate.test_set_location_through_execute_script", "message": "InvalidSessionIdException: Please start a session", "stack": "Traceback (most recent call last):\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 190, in run\n self.tearDown()\n File "Z:\task_1552135541\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 65, in tearDown\n self.marionette.timeout.reset()\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\timeout.py", line 104, in reset\n self.script = DEFAULT_SCRIPT_TIMEOUT\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\timeout.py", line 57, in script\n self._set("script", sec)\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\timeout.py", line 33, in _set\n self._marionette._send_message("WebDriver:SetTimeouts", {name: ms})\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\decorators.py", line 26, in _\n return func(*args, **kwargs)\n File "Z:\task_1552135541\build\venv\lib\site-packages\marionette_driver\marionette.py", line 758, in _send_message\n raise errors.InvalidSessionIdException("Please start a session")\n"}

+++ This bug was initially created as a clone of Bug #1512336 +++

Filed by: nbeleuzu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=215657372&repo=autoland

https://queue.taskcluster.net/v1/task/TcX1OX0DTUu1zZ8dtrJ9uA/runs/0/artifacts/public/logs/live_backing.log

[task 2018-12-05T23:16:19.150Z] 23:16:19 INFO - 1544051779148 Marionette DEBUG Closed connection 17
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_set_location_through_execute_script | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - Traceback (most recent call last):
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - testMethod()
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 131, in test_set_location_through_execute_script
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - message="Target element 'testh1' has not been found")
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/wait.py", line 129, in until
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - rv = condition(self.marionette)
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/expected.py", line 48, in call
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - return _find(marionette, self.locator)
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/expected.py", line 309, in _find
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - el = func(marionette)
[task 2018-12-05T23:17:30.259Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/expected.py", line 45, in <lambda>
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - self.locator = lambda m: m.find_element(*args)
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1836, in find_element
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - body, key="value")
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 36, in _
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - m._handle_socket_failure()
[task 2018-12-05T23:17:30.260Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 844, in _handle_socket_failure
[task 2018-12-05T23:17:30.261Z] 23:17:30 INFO - reraise(IOError, message.format(returncode=returncode, reason=val), tb)
[task 2018-12-05T23:17:30.261Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2018-12-05T23:17:30.261Z] 23:17:30 INFO - return func(*args, **kwargs)
[task 2018-12-05T23:17:30.262Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 756, in _send_message
[task 2018-12-05T23:17:30.262Z] 23:17:30 INFO - msg = self.client.request(name, params)
[task 2018-12-05T23:17:30.263Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 273, in request
[task 2018-12-05T23:17:30.263Z] 23:17:30 INFO - return self.receive()
[task 2018-12-05T23:17:30.263Z] 23:17:30 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/transport.py", line 183, in receive
[task 2018-12-05T23:17:30.264Z] 23:17:30 INFO - raise socket.timeout("Connection timed out after {}s".format(self.socket_timeout))
[task 2018-12-05T23:17:30.264Z] 23:17:30 INFO - TEST-INFO took 431900ms
[task 2018-12-05T23:17:30.265Z] 23:17:30 ERROR - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_set_location_through_execute_script logged while not in progress. Logged with data: {"status": "ERROR", "extra": {"class_name": "test_navigation.TestNavigate", "method_name": "test_set_location_through_execute_script"}, "expected": "PASS", "test": "testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_set_location_through_execute_script", "message": "InvalidSessionIdException: Please start a session", "stack": "Traceback (most recent call last):\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 190, in run\n self.tearDown()\n File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 66, in tearDown\n self.marionette.timeout.reset()\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/timeout.py", line 104, in reset\n self.script = DEFAULT_SCRIPT_TIMEOUT\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/timeout.py", line 57, in script\n self._set("script", sec)\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/timeout.py", line 33, in _set\n self._marionette._send_message("WebDriver:SetTimeouts", {name: ms})\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _\n return func(*args, *kwargs)\n File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 753, in _send_message\n raise errors.InvalidSessionIdException("Please start a session")\n"}
[task 2018-12-05T23:17:30.266Z] 23:17:30 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_type_to_non_remote_tab
[task 2018-12-05T23:17:30.266Z] 23:17:30 INFO - TEST-SKIP | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_type_to_non_remote_tab | took 0ms
[task 2018-12-05T23:17:30.267Z] 23:17:30 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_type_to_remote_tab
[task 2018-12-05T23:17:30.267Z] 23:17:30 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -no-remote -marionette -profile /tmp/tmpfTS1hV.mozrunner
[task 2018-12-05T23:17:31.893Z] 23:17:31 INFO - 1544051851891 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
[task 2018-12-05T23:17:31.895Z] 23:17:31 INFO - 1544051851892 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader

Looks like that the patch on bug 1512336 was not enough. But I expect this bug to be a very low intermittent.

Didn't fail in the last 5 months.