Closed Bug 1541342 Opened 7 years ago Closed 5 years ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchWindowChrome.test_switch_to_new_private_browsing_tab | NoSuchElementException: Failed to trigger opening a new tab: Unable to locate element: star

Categories

(Testing :: Marionette Client and Harness, defect, P5)

Version 3
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, regression)

#[markdown(off)]
Filed by: opoprus [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=237757196&repo=mozilla-central

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

[task 2019-04-03T03:24:01.892Z] 03:24:01 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchWindowChrome.test_switch_to_new_private_browsing_tab
[task 2019-04-03T03:24:01.893Z] 03:24:01 INFO - 1554261841885 Marionette DEBUG 33 <- [1,45,null,{"value":null}]
[task 2019-04-03T03:24:01.894Z] 03:24:01 INFO - 1554261841892 Marionette DEBUG Closed connection 33
[task 2019-04-03T03:24:01.898Z] 03:24:01 INFO - 1554261841895 Marionette DEBUG Accepted connection 34 from 127.0.0.1:60178
[task 2019-04-03T03:24:01.900Z] 03:24:01 INFO - 1554261841897 Marionette DEBUG 34 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-04-03T03:24:01.908Z] 03:24:01 INFO - 1554261841906 Marionette TRACE [2147483649] Frame script loaded
[task 2019-04-03T03:24:01.912Z] 03:24:01 INFO - 1554261841910 Marionette TRACE [2147483649] Frame script registered
[task 2019-04-03T03:24:01.928Z] 03:24:01 INFO - 1554261841922 Marionette DEBUG 34 <- [1,1,null,{"sessionId":"15cbefdc-f534-43de-8656-c5890c5bc611","capabilities":{"browserName":"firefox","browserVersion":"68.0a ... mp/tmpKojoTi.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-04-03T03:24:01.929Z] 03:24:01 INFO - 1554261841926 Marionette DEBUG 34 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2019-04-03T03:24:01.933Z] 03:24:01 INFO - 1554261841927 Marionette DEBUG 34 <- [1,2,null,{"value":null}]
[task 2019-04-03T03:24:01.934Z] 03:24:01 INFO - 1554261841931 Marionette DEBUG 34 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2019-04-03T03:24:01.934Z] 03:24:01 INFO - 1554261841932 Marionette DEBUG 34 <- [1,3,null,{"value":null}]
[task 2019-04-03T03:24:01.943Z] 03:24:01 INFO - 1554261841936 Marionette DEBUG 34 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2019-04-03T03:24:01.944Z] 03:24:01 INFO - 1554261841937 Marionette DEBUG 34 <- [1,4,null,{"value":null}]
[task 2019-04-03T03:24:01.980Z] 03:24:01 INFO - 1554261841975 Marionette DEBUG 34 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2019-04-03T03:24:01.981Z] 03:24:01 INFO - 1554261841976 Marionette DEBUG 34 <- [1,5,null,{"value":"1"}]
[task 2019-04-03T03:24:01.982Z] 03:24:01 INFO - 1554261841978 Marionette DEBUG 34 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-04-03T03:24:01.983Z] 03:24:01 INFO - 1554261841979 Marionette DEBUG 34 <- [1,6,null,["1"]]
[task 2019-04-03T03:24:01.992Z] 03:24:01 INFO - 1554261841984 Marionette DEBUG 34 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2019-04-03T03:24:01.992Z] 03:24:01 INFO - 1554261841985 Marionette DEBUG 34 <- [1,7,null,{"value":"2147483649"}]
[task 2019-04-03T03:24:01.992Z] 03:24:01 INFO - 1554261841987 Marionette DEBUG 34 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:01.993Z] 03:24:01 INFO - 1554261841988 Marionette DEBUG 34 <- [1,8,null,["2147483649"]]
[task 2019-04-03T03:24:01.993Z] 03:24:01 INFO - 1554261841991 Marionette DEBUG 34 -> [0,9,"Marionette:GetContext",{}]
[task 2019-04-03T03:24:01.993Z] 03:24:01 INFO - 1554261841992 Marionette DEBUG 34 <- [1,9,null,{"value":"content"}]
[task 2019-04-03T03:24:02.050Z] 03:24:02 INFO - 1554261842045 Marionette DEBUG 34 -> [0,10,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:02.052Z] 03:24:02 INFO - 1554261842046 Marionette DEBUG 34 <- [1,10,null,{"value":null}]
[task 2019-04-03T03:24:02.053Z] 03:24:02 INFO - 1554261842049 Marionette DEBUG 34 -> [0,11,"WebDriver:ExecuteScript",{"script":"Components.utils.import(\"resource://gre/modules/AppConstants.jsm\");\n\n ... tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py","sandbox":"default","line":64}]
[task 2019-04-03T03:24:02.070Z] 03:24:02 INFO - 1554261842059 Marionette DEBUG 34 <- [1,11,null,{"value":0}]
[task 2019-04-03T03:24:02.071Z] 03:24:02 INFO - 1554261842061 Marionette DEBUG 34 -> [0,12,"Marionette:SetContext",{"value":"content"}]
[task 2019-04-03T03:24:02.072Z] 03:24:02 INFO - 1554261842062 Marionette DEBUG 34 <- [1,12,null,{"value":null}]
[task 2019-04-03T03:24:02.119Z] 03:24:02 INFO - 1554261842113 Marionette DEBUG 34 -> [0,13,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:02.119Z] 03:24:02 INFO - 1554261842115 Marionette DEBUG 34 <- [1,13,null,{"value":null}]
[task 2019-04-03T03:24:02.121Z] 03:24:02 INFO - 1554261842117 Marionette DEBUG 34 -> [0,14,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:02.121Z] 03:24:02 INFO - 1554261842118 Marionette DEBUG 34 <- [1,14,null,["2147483649"]]
[task 2019-04-03T03:24:02.124Z] 03:24:02 INFO - 1554261842123 Marionette DEBUG 34 -> [0,15,"WebDriver:NewWindow",{"type":"tab","focus":true}]
[task 2019-04-03T03:24:02.145Z] 03:24:02 INFO - ++DOCSHELL 0x7fb0a5948800 == 10 [pid = 3430] [id = {f7928e1b-534c-409a-b780-26141d40b0a7}]
[task 2019-04-03T03:24:02.147Z] 03:24:02 INFO - ++DOMWINDOW == 28 (0x7fb0a55f04c0) [pid = 3430] [serial = 28] [outer = (nil)]
[task 2019-04-03T03:24:02.148Z] 03:24:02 INFO - ++DOMWINDOW == 29 (0x7fb0a6b7ac00) [pid = 3430] [serial = 29] [outer = 0x7fb0a55f04c0]
[task 2019-04-03T03:24:02.169Z] 03:24:02 INFO - 1554261842165 Marionette TRACE Received DOM event TabOpen for [object XULElement]
[task 2019-04-03T03:24:02.170Z] 03:24:02 INFO - 1554261842166 Marionette TRACE [8589934620] Frame script loaded
[task 2019-04-03T03:24:02.226Z] 03:24:02 INFO - 1554261842223 Marionette TRACE [8589934620] Frame script registered
[task 2019-04-03T03:24:02.262Z] 03:24:02 INFO - 1554261842257 Marionette DEBUG 34 <- [1,15,null,{"handle":"8589934620","type":"tab"}]
[task 2019-04-03T03:24:02.269Z] 03:24:02 INFO - 1554261842260 Marionette DEBUG 34 -> [0,16,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:02.276Z] 03:24:02 INFO - 1554261842262 Marionette DEBUG 34 <- [1,16,null,["2147483649","8589934620"]]
[task 2019-04-03T03:24:02.283Z] 03:24:02 INFO - 1554261842267 Marionette DEBUG 34 -> [0,17,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:02.289Z] 03:24:02 INFO - 1554261842270 Marionette DEBUG 34 <- [1,17,null,["2147483649","8589934620"]]
[task 2019-04-03T03:24:02.297Z] 03:24:02 INFO - 1554261842275 Marionette DEBUG 34 -> [0,18,"WebDriver:SwitchToWindow",{"handle":"8589934620","focus":true,"name":"8589934620"}]
[task 2019-04-03T03:24:02.303Z] 03:24:02 INFO - 1554261842279 Marionette DEBUG 34 <- [1,18,null,{"value":null}]
[task 2019-04-03T03:24:02.304Z] 03:24:02 INFO - 1554261842284 Marionette DEBUG 34 -> [0,19,"Marionette:GetContext",{}]
[task 2019-04-03T03:24:02.305Z] 03:24:02 INFO - 1554261842286 Marionette DEBUG 34 <- [1,19,null,{"value":"chrome"}]
[task 2019-04-03T03:24:02.305Z] 03:24:02 INFO - 1554261842290 Marionette DEBUG 34 -> [0,20,"Marionette:SetContext",{"value":"content"}]
[task 2019-04-03T03:24:02.305Z] 03:24:02 INFO - 1554261842294 Marionette DEBUG 34 <- [1,20,null,{"value":null}]
[task 2019-04-03T03:24:02.306Z] 03:24:02 INFO - 1554261842298 Marionette DEBUG 34 -> [0,21,"WebDriver:Navigate",{"url":"about:privatebrowsing"}]
[task 2019-04-03T03:24:02.343Z] 03:24:02 INFO - 1554261842336 Marionette TRACE [8589934620] Received DOM event beforeunload for about:blank
[task 2019-04-03T03:24:02.343Z] 03:24:02 INFO - 1554261842341 Marionette TRACE [8589934620] Received DOM event pagehide for about:blank
[task 2019-04-03T03:24:02.363Z] 03:24:02 INFO - 1554261842349 Marionette TRACE [8589934620] Received DOM event unload for about:blank
[task 2019-04-03T03:24:02.364Z] 03:24:02 INFO - ++DOMWINDOW == 30 (0x7fb0be1e6800) [pid = 3430] [serial = 30] [outer = 0x7fb0a55f04c0]
[task 2019-04-03T03:24:02.388Z] 03:24:02 INFO - 1554261842384 Marionette TRACE [8589934620] Received DOM event DOMContentLoaded for about:blank
[task 2019-04-03T03:24:02.436Z] 03:24:02 INFO - 1554261842432 Marionette TRACE [8589934620] Received DOM event pageshow for about:blank
[task 2019-04-03T03:24:02.472Z] 03:24:02 INFO - 1554261842463 Marionette DEBUG 34 <- [1,21,null,{"value":null}]
[task 2019-04-03T03:24:02.495Z] 03:24:02 INFO - ++DOCSHELL 0x7fb8db179000 == 1 [pid = 3516] [id = {4c2f681a-5ab6-4537-8300-44ee9a4ed676}]
[task 2019-04-03T03:24:02.495Z] 03:24:02 INFO - ++DOMWINDOW == 1 (0x7fb8c26e5020) [pid = 3516] [serial = 1] [outer = (nil)]
[task 2019-04-03T03:24:02.579Z] 03:24:02 INFO - ++DOMWINDOW == 2 (0x7fb8c2627000) [pid = 3516] [serial = 2] [outer = 0x7fb8c26e5020]
[task 2019-04-03T03:24:02.627Z] 03:24:02 INFO - 1554261842620 Marionette DEBUG 34 -> [0,22,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:02.627Z] 03:24:02 INFO - 1554261842622 Marionette DEBUG 34 <- [1,22,null,["2147483649","8589934620"]]
[task 2019-04-03T03:24:02.666Z] 03:24:02 INFO - 1554261842652 Marionette DEBUG 34 -> [0,23,"Marionette:GetContext",{}]
[task 2019-04-03T03:24:02.666Z] 03:24:02 INFO - 1554261842653 Marionette DEBUG 34 <- [1,23,null,{"value":"content"}]
[task 2019-04-03T03:24:02.666Z] 03:24:02 INFO - 1554261842656 Marionette DEBUG 34 -> [0,24,"Marionette:SetContext",{"value":"content"}]
[task 2019-04-03T03:24:02.666Z] 03:24:02 INFO - 1554261842657 Marionette DEBUG 34 <- [1,24,null,{"value":null}]
[task 2019-04-03T03:24:02.702Z] 03:24:02 INFO - 1554261842688 Marionette DEBUG 34 -> [0,25,"WebDriver:FindElement",{"using":"id","value":"startPrivateBrowsing"}]
[task 2019-04-03T03:24:02.940Z] 03:24:02 INFO - 1554261842935 Marionette TRACE [17179869185] Frame script loaded
[task 2019-04-03T03:24:03.001Z] 03:24:03 INFO - 1554261842995 Marionette TRACE [17179869185] Frame script registered
[task 2019-04-03T03:24:03.017Z] 03:24:03 INFO - [Child 3516, Main Thread] WARNING: HeadlessLookAndFeel::GetIntImpl called with an unrecognized aID: file /builds/worker/workspace/build/src/widget/headless/HeadlessLookAndFeelGTK.cpp, line 292
[task 2019-04-03T03:24:03.136Z] 03:24:03 INFO - [Parent 3235, Main Thread] WARNING: '!parent', file /builds/worker/workspace/build/src/netwerk/ipc/NeckoParent.cpp, line 955
[task 2019-04-03T03:24:03.212Z] 03:24:03 INFO - 1554261843205 Marionette DEBUG 34 <- [1,25,{"error":"no such element","message":"Unable to locate element: startPrivateBrowsing","stacktrace":"WebDriverError@chro ... :528:3\nregisterSelf@chrome://marionette/content/listener.js:456:5\n@chrome://marionette/content/listener.js:1682:1\n"},null]
[task 2019-04-03T03:24:03.233Z] 03:24:03 INFO - ++DOMWINDOW == 3 (0x7fb8c3c11800) [pid = 3516] [serial = 3] [outer = 0x7fb8c26e5020]
[task 2019-04-03T03:24:03.270Z] 03:24:03 INFO - 1554261843254 Marionette DEBUG 34 -> [0,26,"Marionette:SetContext",{"value":"content"}]
[task 2019-04-03T03:24:03.275Z] 03:24:03 INFO - 1554261843256 Marionette DEBUG 34 <- [1,26,null,{"value":null}]
[task 2019-04-03T03:24:03.281Z] 03:24:03 INFO - 1554261843263 Marionette DEBUG 34 -> [0,27,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:03.286Z] 03:24:03 INFO - 1554261843264 Marionette DEBUG 34 <- [1,27,null,{"value":null}]
[task 2019-04-03T03:24:03.307Z] 03:24:03 INFO - Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-04-03T03:24:03.309Z] 03:24:03 INFO - [Child 3536, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/netwerk/base/nsIOService.cpp, line 942
[task 2019-04-03T03:24:03.366Z] 03:24:03 INFO - 1554261843362 Marionette DEBUG 34 -> [0,28,"Marionette:GetContext",{}]
[task 2019-04-03T03:24:03.371Z] 03:24:03 INFO - 1554261843363 Marionette DEBUG 34 <- [1,28,null,{"value":"chrome"}]
[task 2019-04-03T03:24:03.402Z] 03:24:03 INFO - 1554261843392 Marionette DEBUG 34 -> [0,29,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:03.405Z] 03:24:03 INFO - 1554261843394 Marionette DEBUG 34 <- [1,29,null,{"value":null}]
[task 2019-04-03T03:24:03.407Z] 03:24:03 INFO - 1554261843396 Marionette DEBUG 34 -> [0,30,"WebDriver:TakeScreenshot",{"highlights":null,"full":true,"hash":false,"id":null,"scroll":true}]
[task 2019-04-03T03:24:03.426Z] 03:24:03 INFO - [Parent 3235, Main Thread] WARNING: Remote iframe not rendered: file /builds/worker/workspace/build/src/layout/ipc/RenderFrame.cpp, line 257
[task 2019-04-03T03:24:03.507Z] 03:24:03 INFO - 1554261843503 Marionette DEBUG 34 <- [1,30,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQQCAYAAAC9RfbYAAAgAElEQVR4nOzda4ycB3nocX+s2vRCISqgivJhz4dIRQfntBGold2qwId1 ... lAAAAAABgTgAAAAAAwJgABAAAAYEwAAgAAAMCYAAQAAACAMQEIAAAAAGMCEAAAAADGBCAAAAAAjAlAAAAAABgTgAAAAAAwFgj1WD/hjI9NAAAAAElFTkSuQmCC"}]
[task 2019-04-03T03:24:03.531Z] 03:24:03 INFO - 1554261843527 Marionette DEBUG 34 -> [0,31,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:03.537Z] 03:24:03 INFO - 1554261843528 Marionette DEBUG 34 <- [1,31,null,{"value":null}]
[task 2019-04-03T03:24:03.552Z] 03:24:03 INFO - 1554261843545 Marionette DEBUG 34 -> [0,32,"Marionette:GetContext",{}]
[task 2019-04-03T03:24:03.557Z] 03:24:03 INFO - 1554261843548 Marionette DEBUG 34 <- [1,32,null,{"value":"chrome"}]
[task 2019-04-03T03:24:03.569Z] 03:24:03 INFO - 1554261843564 Marionette DEBUG 34 -> [0,33,"Marionette:SetContext",{"value":"content"}]
[task 2019-04-03T03:24:03.589Z] 03:24:03 INFO - 1554261843574 Marionette DEBUG 34 <- [1,33,null,{"value":null}]
[task 2019-04-03T03:24:03.594Z] 03:24:03 INFO - 1554261843582 Marionette DEBUG 34 -> [0,34,"WebDriver:GetPageSource",{}]
[task 2019-04-03T03:24:03.627Z] 03:24:03 INFO - 1554261843617 Marionette DEBUG 34 <- [1,34,null,{"value":"<html xmlns=\"http://www.w3.org/1999/xhtml\" class=\"private no-search-ui\">\n <head>\n <meta http-e ... ate-browsing-myths\" data-l10n-id=\"about-private-browsing-info-myths\"></a>\n </div>\n </div>\n </body>\n</html>"}]
[task 2019-04-03T03:24:03.706Z] 03:24:03 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_chrome.py TestSwitchWindowChrome.test_switch_to_new_private_browsing_tab | NoSuchElementException: Failed to trigger opening a new tab: Unable to locate element: startPrivateBrowsing
[task 2019-04-03T03:24:03.708Z] 03:24:03 INFO - stacktrace:
[task 2019-04-03T03:24:03.709Z] 03:24:03 INFO - WebDriverError@chrome://marionette/content/error.js:179:5
[task 2019-04-03T03:24:03.712Z] 03:24:03 INFO - NoSuchElementError@chrome://marionette/content/error.js:389:5
[task 2019-04-03T03:24:03.714Z] 03:24:03 INFO - element.find/</<@chrome://marionette/content/element.js:339:16
[task 2019-04-03T03:24:03.717Z] 03:24:03 INFO - MessageListener.receiveMessage*startListeners@chrome://marionette/content/listener.js:528:3
[task 2019-04-03T03:24:03.719Z] 03:24:03 INFO - registerSelf@chrome://marionette/content/listener.js:456:5
[task 2019-04-03T03:24:03.721Z] 03:24:03 INFO - @chrome://marionette/content/listener.js:1682:1
[task 2019-04-03T03:24:03.724Z] 03:24:03 INFO - Traceback (most recent call last):
[task 2019-04-03T03:24:03.725Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-04-03T03:24:03.726Z] 03:24:03 INFO - testMethod()
[task 2019-04-03T03:24:03.728Z] 03:24:03 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py", line 142, in test_switch_to_new_private_browsing_tab
[task 2019-04-03T03:24:03.729Z] 03:24:03 INFO - new_pb_tab = self.open_tab(open_private_browsing_window_firefox)
[task 2019-04-03T03:24:03.731Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/runner/mixins/window_manager.py", line 75, in open_tab
[task 2019-04-03T03:24:03.732Z] 03:24:03 INFO - reraise(exc, 'Failed to trigger opening a new tab: {}'.format(val), tb)
[task 2019-04-03T03:24:03.733Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/runner/mixins/window_manager.py", line 66, in open_tab
[task 2019-04-03T03:24:03.734Z] 03:24:03 INFO - callback()
[task 2019-04-03T03:24:03.736Z] 03:24:03 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_switch_window_content.py", line 131, in open_private_browsing_window_firefox
[task 2019-04-03T03:24:03.737Z] 03:24:03 INFO - self.marionette.find_element(By.ID, "startPrivateBrowsing").click()
[task 2019-04-03T03:24:03.738Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1694, in find_element
[task 2019-04-03T03:24:03.739Z] 03:24:03 INFO - body, key="value")
[task 2019-04-03T03:24:03.741Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _
[task 2019-04-03T03:24:03.742Z] 03:24:03 INFO - return func(*args, **kwargs)
[task 2019-04-03T03:24:03.744Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 598, in _send_message
[task 2019-04-03T03:24:03.745Z] 03:24:03 INFO - self._handle_error(err)
[task 2019-04-03T03:24:03.748Z] 03:24:03 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 618, in _handle_error
[task 2019-04-03T03:24:03.749Z] 03:24:03 INFO - raise errors.lookup(error)(message, stacktrace=stacktrace)
[task 2019-04-03T03:24:03.750Z] 03:24:03 INFO - TEST-INFO took 1735ms
[task 2019-04-03T03:24:03.752Z] 03:24:03 INFO - 1554261843621 Marionette DEBUG 34 -> [0,35,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-04-03T03:24:03.757Z] 03:24:03 INFO - 1554261843622 Marionette DEBUG 34 <- [1,35,null,{"value":null}]
[task 2019-04-03T03:24:03.763Z] 03:24:03 INFO - 1554261843635 Marionette DEBUG 34 -> [0,36,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-04-03T03:24:03.768Z] 03:24:03 INFO - 1554261843637 Marionette DEBUG 34 <- [1,36,null,["1"]]
[task 2019-04-03T03:24:03.773Z] 03:24:03 INFO - 1554261843688 Marionette DEBUG 34 -> [0,37,"WebDriver:SwitchToWindow",{"handle":"1","focus":true,"name":"1"}]
[task 2019-04-03T03:24:03.787Z] 03:24:03 INFO - 1554261843782 Marionette DEBUG 34 <- [1,37,null,{"value":null}]
[task 2019-04-03T03:24:03.809Z] 03:24:03 INFO - 1554261843796 Marionette DEBUG 34 -> [0,38,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:03.814Z] 03:24:03 INFO - 1554261843797 Marionette DEBUG 34 <- [1,38,null,["2147483649","17179869185"]]
[task 2019-04-03T03:24:03.845Z] 03:24:03 INFO - 1554261843831 Marionette DEBUG 34 -> [0,39,"WebDriver:SwitchToWindow",{"handle":"17179869185","focus":true,"name":"17179869185"}]
[task 2019-04-03T03:24:03.853Z] 03:24:03 INFO - 1554261843834 Marionette DEBUG 34 <- [1,39,null,{"value":null}]
[task 2019-04-03T03:24:03.859Z] 03:24:03 INFO - 1554261843845 Marionette DEBUG 34 -> [0,40,"WebDriver:CloseWindow",{}]
[task 2019-04-03T03:24:03.923Z] 03:24:03 INFO - 1554261843919 Marionette TRACE Received DOM event TabClose for [object XULElement]
[task 2019-04-03T03:24:03.986Z] 03:24:03 INFO - --DOCSHELL 0x7f396de50800 == 60 [pid = 3272] [id = {3511a115-7698-4fe2-b81f-38231401336c}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.987Z] 03:24:03 INFO - --DOCSHELL 0x7f398987a000 == 59 [pid = 3272] [id = {e04d8935-0080-438a-ba02-bb5081190d69}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.989Z] 03:24:03 INFO - --DOCSHELL 0x7f396da29000 == 58 [pid = 3272] [id = {0e7dc061-de62-499f-a68d-d9d5ddbfd122}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.990Z] 03:24:03 INFO - --DOCSHELL 0x7f396da2a800 == 57 [pid = 3272] [id = {1860f3cd-ff20-4265-8272-78c6804f54b8}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.990Z] 03:24:03 INFO - --DOCSHELL 0x7f396de63000 == 56 [pid = 3272] [id = {5e93516f-cda6-428a-900f-cbb9eb7fa368}] [url = http://127.0.0.1:36368/page/1]
[task 2019-04-03T03:24:03.991Z] 03:24:03 INFO - --DOCSHELL 0x7f396de63800 == 55 [pid = 3272] [id = {b99ebb31-0473-4280-a196-1de12becca01}] [url = http://127.0.0.1:36368/page/2?title=Fish]
[task 2019-04-03T03:24:03.991Z] 03:24:03 INFO - --DOCSHELL 0x7f396de64000 == 54 [pid = 3272] [id = {c260504e-2827-40f9-9569-f64f70bf035a}] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:03.992Z] 03:24:03 INFO - --DOCSHELL 0x7f396de64800 == 53 [pid = 3272] [id = {8748f8bf-6419-4795-aad7-41ba2ad6a131}] [url = http://127.0.0.1:36368/framesetPage2.html]
[task 2019-04-03T03:24:03.992Z] 03:24:03 INFO - --DOCSHELL 0x7f396de65000 == 52 [pid = 3272] [id = {7071f793-a84e-4cc3-89ee-0301a364b0bf}] [url = http://127.0.0.1:36368/xhtmlTest.html]
[task 2019-04-03T03:24:03.993Z] 03:24:03 INFO - --DOCSHELL 0x7f396de65800 == 51 [pid = 3272] [id = {1333246a-43b6-491d-a7f4-a6432281fd09}] [url = http://127.0.0.1:36368/test_iframe.html]
[task 2019-04-03T03:24:03.993Z] 03:24:03 INFO - --DOCSHELL 0x7f396de66000 == 50 [pid = 3272] [id = {5325e95c-9c3c-4cc2-8fdd-4b07ea597ded}] [url = http://127.0.0.1:36368/page/3]
[task 2019-04-03T03:24:03.994Z] 03:24:03 INFO - --DOCSHELL 0x7f396de6e800 == 49 [pid = 3272] [id = {f802589a-cf74-4297-95dc-a636b328de50}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.994Z] 03:24:03 INFO - --DOCSHELL 0x7f396de6f000 == 48 [pid = 3272] [id = {2e1b59c1-067f-4474-8fba-c243c71e168c}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.995Z] 03:24:03 INFO - --DOCSHELL 0x7f396da26000 == 47 [pid = 3272] [id = {3ed3495d-f049-4fc1-aaf1-ad9406a266c0}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.996Z] 03:24:03 INFO - --DOCSHELL 0x7f396da29800 == 46 [pid = 3272] [id = {a086edbc-68fa-42b8-8453-001c7ca19f6c}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.997Z] 03:24:03 INFO - --DOCSHELL 0x7f3971758800 == 45 [pid = 3272] [id = {72c5e7d1-780f-41cd-83a0-980cdfbc3413}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.997Z] 03:24:03 INFO - --DOCSHELL 0x7f39712b3000 == 44 [pid = 3272] [id = {c8ee59fd-1100-42e7-a8a3-d36de9bb7076}] [url = http://127.0.0.1:36368/test_inner_iframe.html]
[task 2019-04-03T03:24:03.999Z] 03:24:03 INFO - --DOCSHELL 0x7f3971759800 == 43 [pid = 3272] [id = {7a7a68be-47aa-4b2e-a0cd-49a85bce22f0}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:03.999Z] 03:24:03 INFO - --DOCSHELL 0x7f396da1c800 == 42 [pid = 3272] [id = {8cfd1e19-08ec-49a6-bf21-bb5f8ff9caec}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.000Z] 03:24:03 INFO - --DOCSHELL 0x7f397175a000 == 41 [pid = 3272] [id = {c65d754c-bb4d-413a-b183-4fe0569d3a22}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.001Z] 03:24:03 INFO - --DOCSHELL 0x7f39723c5800 == 40 [pid = 3272] [id = {23cb277e-7e51-45fa-9d80-1d304de061f5}] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.003Z] 03:24:04 INFO - --DOCSHELL 0x7f39723c2000 == 39 [pid = 3272] [id = {a3e60500-a650-48da-acfa-aac3236ed628}] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.004Z] 03:24:04 INFO - --DOCSHELL 0x7f396da1e800 == 38 [pid = 3272] [id = {b463453a-090e-455e-abe5-85d34d6678f1}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.006Z] 03:24:04 INFO - --DOCSHELL 0x7f396da1e000 == 37 [pid = 3272] [id = {eb1817db-b4c2-4c08-a97b-347398255618}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.007Z] 03:24:04 INFO - --DOCSHELL 0x7f396da19800 == 36 [pid = 3272] [id = {5ff588c9-4670-4cb4-b35d-ff40a7677688}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.008Z] 03:24:04 INFO - --DOCSHELL 0x7f396da19000 == 35 [pid = 3272] [id = {46b2e91c-ab19-40ab-b099-576f93ac35af}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.010Z] 03:24:04 INFO - --DOCSHELL 0x7f39723cb800 == 34 [pid = 3272] [id = {0eeb3bcd-aae8-4a17-b618-849fb2c2c97f}] [url = http://127.0.0.1:36368/xhtmlTest.html]
[task 2019-04-03T03:24:04.011Z] 03:24:04 INFO - --DOCSHELL 0x7f398987c000 == 33 [pid = 3272] [id = {63c41400-c545-437b-9fd0-12b1e8369307}] [url = http://127.0.0.1:36368/test_iframe.html]
[task 2019-04-03T03:24:04.013Z] 03:24:04 INFO - --DOCSHELL 0x7f398987d800 == 32 [pid = 3272] [id = {0c24d104-3fc1-4549-9fa2-520e30e2983f}] [url = http://127.0.0.1:36368/page/3]
[task 2019-04-03T03:24:04.015Z] 03:24:04 INFO - --DOCSHELL 0x7f39723cb000 == 31 [pid = 3272] [id = {1b7b5c51-af1a-4a0f-8c2e-a63a75de6b6f}] [url = http://127.0.0.1:36368/framesetPage2.html]
[task 2019-04-03T03:24:04.018Z] 03:24:04 INFO - --DOCSHELL 0x7f39723c8000 == 30 [pid = 3272] [id = {bbd1aa2a-6407-4a68-8b44-6574e4c4ea78}] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.019Z] 03:24:04 INFO - --DOCSHELL 0x7f39723c4000 == 29 [pid = 3272] [id = {42ac8a24-9cbf-419e-a923-2159f68b4835}] [url = http://127.0.0.1:36368/page/2?title=Fish]
[task 2019-04-03T03:24:04.021Z] 03:24:04 INFO - --DOCSHELL 0x7f39723c3800 == 28 [pid = 3272] [id = {fbfb82b1-9902-4ed0-ac84-f1cd8c42a334}] [url = http://127.0.0.1:36368/page/1]
[task 2019-04-03T03:24:04.022Z] 03:24:04 INFO - --DOCSHELL 0x7f39714ee800 == 27 [pid = 3272] [id = {accf7948-03b2-410b-9fc0-31139c47700c}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.023Z] 03:24:04 INFO - --DOCSHELL 0x7f39714ee000 == 26 [pid = 3272] [id = {d02c7f87-b852-4f22-b8c8-93b6c24bf13f}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.026Z] 03:24:04 INFO - --DOCSHELL 0x7f39714f4000 == 25 [pid = 3272] [id = {515e400c-fb92-4042-a5de-093aac56d2aa}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.028Z] 03:24:04 INFO - --DOCSHELL 0x7f39714f3800 == 24 [pid = 3272] [id = {dac1d492-c312-4127-90a8-f3fd135fbd6d}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.030Z] 03:24:04 INFO - --DOCSHELL 0x7f39714ed000 == 23 [pid = 3272] [id = {96e88067-7afc-4214-a40a-ffce40d18ef8}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.031Z] 03:24:04 INFO - --DOCSHELL 0x7f39714da800 == 22 [pid = 3272] [id = {d53e333e-adfd-49d2-9b5a-c4d6672729ff}] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.033Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e4800 == 21 [pid = 3272] [id = {e28c342b-c6de-4dab-ab46-a4100a0f8e6e}] [url = http://127.0.0.1:36368/page/3]
[task 2019-04-03T03:24:04.034Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e4000 == 20 [pid = 3272] [id = {978c91e8-d4c2-4f7a-81ce-b62900381e0e}] [url = http://127.0.0.1:36368/test_iframe.html]
[task 2019-04-03T03:24:04.036Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e3800 == 19 [pid = 3272] [id = {16575020-54aa-4d03-b4bf-c5c2f02a799c}] [url = http://127.0.0.1:36368/xhtmlTest.html]
[task 2019-04-03T03:24:04.037Z] 03:24:04 INFO - --DOMWINDOW == 76 (0x7f396e61ce20) [pid = 3272] [serial = 55] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.037Z] 03:24:04 INFO - --DOMWINDOW == 75 (0x7f39715d7d40) [pid = 3272] [serial = 46] [outer = (nil)] [url = http://127.0.0.1:36368/test_iframe.html]
[task 2019-04-03T03:24:04.038Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e3000 == 18 [pid = 3272] [id = {cd02af3b-333c-4067-b2c5-7f9380931ee6}] [url = http://127.0.0.1:36368/framesetPage2.html]
[task 2019-04-03T03:24:04.039Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e2800 == 17 [pid = 3272] [id = {bc35bfa4-b835-4108-a69f-2fca8e3a68bb}] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.040Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e2000 == 16 [pid = 3272] [id = {9da8a6e2-6330-401b-8428-30c7c248e638}] [url = http://127.0.0.1:36368/page/2?title=Fish]
[task 2019-04-03T03:24:04.041Z] 03:24:04 INFO - --DOCSHELL 0x7f39714e1800 == 15 [pid = 3272] [id = {de5b97a6-eb53-44e5-9d69-7549932dc65d}] [url = http://127.0.0.1:36368/page/1]
[task 2019-04-03T03:24:04.041Z] 03:24:04 INFO - --DOMWINDOW == 74 (0x7f396e64e200) [pid = 3272] [serial = 58] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.042Z] 03:24:04 INFO - --DOMWINDOW == 73 (0x7f39715d77a0) [pid = 3272] [serial = 43] [outer = (nil)] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.043Z] 03:24:04 INFO - --DOMWINDOW == 72 (0x7f396e61c6a0) [pid = 3272] [serial = 102] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.043Z] 03:24:04 INFO - --DOMWINDOW == 71 (0x7f39715d75c0) [pid = 3272] [serial = 42] [outer = (nil)] [url = http://127.0.0.1:36368/page/2?title=Fish]
[task 2019-04-03T03:24:04.044Z] 03:24:04 INFO - --DOMWINDOW == 70 (0x7f396e61c880) [pid = 3272] [serial = 103] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.045Z] 03:24:04 INFO - --DOMWINDOW == 69 (0x7f396de21b60) [pid = 3272] [serial = 99] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.045Z] 03:24:04 INFO - --DOMWINDOW == 68 (0x7f3971403100) [pid = 3272] [serial = 64] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.047Z] 03:24:04 INFO - --DOMWINDOW == 67 (0x7f39715d7f20) [pid = 3272] [serial = 47] [outer = (nil)] [url = http://127.0.0.1:36368/page/3]
[task 2019-04-03T03:24:04.048Z] 03:24:04 INFO - --DOMWINDOW == 66 (0x7f397123f880) [pid = 3272] [serial = 93] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.048Z] 03:24:04 INFO - --DOMWINDOW == 65 (0x7f396e64e020) [pid = 3272] [serial = 57] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.049Z] 03:24:04 INFO - --DOMWINDOW == 64 (0x7f39715d7b60) [pid = 3272] [serial = 45] [outer = (nil)] [url = http://127.0.0.1:36368/xhtmlTest.html]
[task 2019-04-03T03:24:04.050Z] 03:24:04 INFO - --DOMWINDOW == 63 (0x7f39715d73e0) [pid = 3272] [serial = 41] [outer = (nil)] [url = http://127.0.0.1:36368/page/1]
[task 2019-04-03T03:24:04.051Z] 03:24:04 INFO - --DOMWINDOW == 62 (0x7f39711e1f20) [pid = 3272] [serial = 13] [outer = (nil)] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.052Z] 03:24:04 INFO - --DOMWINDOW == 61 (0x7f396de3d4c0) [pid = 3272] [serial = 97] [outer = (nil)] [url = http://127.0.0.1:36368/test_inner_iframe.html]
[task 2019-04-03T03:24:04.052Z] 03:24:04 INFO - --DOMWINDOW == 60 (0x7f39715d7980) [pid = 3272] [serial = 44] [outer = (nil)] [url = http://127.0.0.1:36368/framesetPage2.html]
[task 2019-04-03T03:24:04.053Z] 03:24:04 INFO - --DOMWINDOW == 59 (0x7f396e726880) [pid = 3272] [serial = 119] [outer = (nil)] [url = http://127.0.0.1:36368/formPage.html]
[task 2019-04-03T03:24:04.053Z] 03:24:04 INFO - --DOMWINDOW == 58 (0x7f396e625020) [pid = 3272] [serial = 56] [outer = (nil)] [url = http://127.0.0.1:36368/test.html]
[task 2019-04-03T03:24:04.054Z] 03:24:04 INFO - 1554261844026 Marionette TRACE Received observer notification message-manager-disconnect
[task 2019-04-03T03:24:04.056Z] 03:24:04 INFO - 1554261844033 Marionette DEBUG 34 <- [1,40,null,["2147483649"]]
[task 2019-04-03T03:24:04.063Z] 03:24:04 INFO - 1554261844061 Marionette DEBUG 34 -> [0,41,"WebDriver:SwitchToWindow",{"handle":"2147483649","focus":true,"name":"2147483649"}]
[task 2019-04-03T03:24:04.066Z] 03:24:04 INFO - 1554261844066 Marionette DEBUG 34 <- [1,41,null,{"value":null}]
[task 2019-04-03T03:24:04.075Z] 03:24:04 INFO - 1554261844072 Marionette DEBUG 34 -> [0,42,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-04-03T03:24:04.076Z] 03:24:04 INFO - 1554261844074 Marionette DEBUG 34 <- [1,42,null,["1"]]
[task 2019-04-03T03:24:04.086Z] 03:24:04 INFO - 1554261844079 Marionette DEBUG 34 -> [0,43,"WebDriver:GetWindowHandles",{}]
[task 2019-04-03T03:24:04.087Z] 03:24:04 INFO - 1554261844081 Marionette DEBUG 34 <- [1,43,null,["2147483649"]]
[task 2019-04-03T03:24:04.106Z] 03:24:04 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-04-03T03:24:04.107Z] 03:24:04 INFO - 1554261844096 Marionette DEBUG 34 -> [0,44,"WebDriver:DeleteSession",{}]
[task 2019-04-03T03:24:04.109Z] 03:24:04 INFO - 1554261844099 Marionette DEBUG 34 <- [1,44,null,{"value":null}]

Problem is that we have an overlap with loading about:blank:

[task 2019-04-03T03:24:02.306Z] 03:24:02 INFO - 1554261842298 Marionette DEBUG 34 -> [0,21,"WebDriver:Navigate",{"url":"about:privatebrowsing"}]
[task 2019-04-03T03:24:02.343Z] 03:24:02 INFO - 1554261842336 Marionette TRACE [8589934620] Received DOM event beforeunload for about:blank
[task 2019-04-03T03:24:02.343Z] 03:24:02 INFO - 1554261842341 Marionette TRACE [8589934620] Received DOM event pagehide for about:blank
[task 2019-04-03T03:24:02.363Z] 03:24:02 INFO - 1554261842349 Marionette TRACE [8589934620] Received DOM event unload for about:blank
[task 2019-04-03T03:24:02.364Z] 03:24:02 INFO - ++DOMWINDOW == 30 (0x7fb0be1e6800) [pid = 3430] [serial = 30] [outer = 0x7fb0a55f04c0]
[task 2019-04-03T03:24:02.388Z] 03:24:02 INFO - 1554261842384 Marionette TRACE [8589934620] Received DOM event DOMContentLoaded for about:blank
[task 2019-04-03T03:24:02.436Z] 03:24:02 INFO - 1554261842432 Marionette TRACE [8589934620] Received DOM event pageshow for about:blank

Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Product: Testing → Remote Protocol
Moving bug to Testing::Marionette Client and Harness component per bug 1815831.
Component: Marionette → Marionette Client and Harness
Product: Remote Protocol → Testing
You need to log in before you can comment on or make changes to this bug.