Closed Bug 1665489 Opened 4 years ago Closed 4 years ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%

Categories

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

Product:
Testing
Component:
Marionette Client and Harness
Type:
defect

Tracking

(firefox-esr78 wontfix, firefox81 wontfix, firefox82 wontfix, firefox83 fixed)

Status:
RESOLVED FIXED
Milestone:
83 Branch
Tracking Flags:
Tracking Status
firefox-esr78 --- wontfix
firefox81 --- wontfix
firefox82 --- wontfix
firefox83 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: whimboo)

References

Details

(Keywords: assertion, intermittent-failure, Whiteboard: [marionette-fission-mvp][simple])

Attachments

(1 file)

Bug 1665489 - [marionette] Wait for the expected URL when navigation starts from inside a frame.
47 bytes, text/x-phabricator-request
Details | Review

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

[task 2020-09-16T05:08:20.265Z] 05:08:20     INFO - TEST-PASS | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_to_same_image_document_twice | took 725ms
[task 2020-09-16T05:08:20.265Z] 05:08:20     INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context
[task 2020-09-16T05:08:20.265Z] 05:08:20     INFO -  1600232900263	Marionette	DEBUG	Closed connection 15
[task 2020-09-16T05:08:20.266Z] 05:08:20     INFO -  1600232900264	Marionette	DEBUG	Accepted connection 16 from 127.0.0.1:51214
[task 2020-09-16T05:08:20.270Z] 05:08:20     INFO -  1600232900266	Marionette	DEBUG	16 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2020-09-16T05:08:20.271Z] 05:08:20     INFO -  1600232900269	Marionette	TRACE	[16] Frame script loaded
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900272	Marionette	DEBUG	16 <- [1,1,null,{"sessionId":"85ad4ce8-85bf-d54b-ae60-9cd2429153f6","capabilities":{"browserName":"firefox","browserVersion":"82.0a ... /T/tmp9wumuz.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900274	Marionette	DEBUG	16 -> [0,2,"WebDriver:SetTimeouts",{"script":30000}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900274	Marionette	DEBUG	16 <- [1,2,null,{"value":null}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900276	Marionette	DEBUG	16 -> [0,3,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900276	Marionette	DEBUG	16 <- [1,3,null,{"value":null}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900277	Marionette	DEBUG	16 -> [0,4,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900278	Marionette	DEBUG	16 <- [1,4,null,{"value":null}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900279	Marionette	DEBUG	16 -> [0,5,"WebDriver:GetChromeWindowHandle",{}]
[task 2020-09-16T05:08:20.282Z] 05:08:20     INFO -  1600232900279	Marionette	DEBUG	16 <- [1,5,null,{"value":"14"}]
[task 2020-09-16T05:08:20.283Z] 05:08:20     INFO -  1600232900280	Marionette	DEBUG	16 -> [0,6,"WebDriver:GetChromeWindowHandles",{}]
[task 2020-09-16T05:08:20.283Z] 05:08:20     INFO -  1600232900281	Marionette	DEBUG	16 <- [1,6,null,["14"]]
[task 2020-09-16T05:08:20.292Z] 05:08:20     INFO -  1600232900282	Marionette	DEBUG	16 -> [0,7,"WebDriver:GetWindowHandle",{}]
[task 2020-09-16T05:08:20.292Z] 05:08:20     INFO -  1600232900283	Marionette	DEBUG	16 <- [1,7,null,{"value":"16"}]
[task 2020-09-16T05:08:20.292Z] 05:08:20     INFO -  1600232900284	Marionette	DEBUG	16 -> [0,8,"WebDriver:GetWindowHandles",{}]
[task 2020-09-16T05:08:20.292Z] 05:08:20     INFO -  1600232900284	Marionette	DEBUG	16 <- [1,8,null,["16"]]
[task 2020-09-16T05:08:20.292Z] 05:08:20     INFO -  1600232900286	Marionette	DEBUG	16 -> [0,9,"WebDriver:GetWindowHandles",{}]
[task 2020-09-16T05:08:20.293Z] 05:08:20     INFO -  1600232900286	Marionette	DEBUG	16 <- [1,9,null,["16"]]
[task 2020-09-16T05:08:20.300Z] 05:08:20     INFO -  1600232900287	Marionette	DEBUG	16 -> [0,10,"WebDriver:NewWindow",{"type":"tab","focus":false,"private":false}]
[task 2020-09-16T05:08:20.300Z] 05:08:20     INFO -  1600232900297	Marionette	TRACE	Received DOM event TabOpen for [object XULElement]
[task 2020-09-16T05:08:20.314Z] 05:08:20     INFO -  1600232900303	Marionette	TRACE	[72] Frame script loaded
[task 2020-09-16T05:08:20.401Z] 05:08:20     INFO -  1600232900366	Marionette	DEBUG	16 <- [1,10,null,{"handle":"72","type":"tab"}]
[task 2020-09-16T05:08:20.401Z] 05:08:20     INFO -  1600232900376	Marionette	DEBUG	16 -> [0,11,"WebDriver:GetWindowHandles",{}]
[task 2020-09-16T05:08:20.401Z] 05:08:20     INFO -  1600232900378	Marionette	DEBUG	16 <- [1,11,null,["16","72"]]
[task 2020-09-16T05:08:20.435Z] 05:08:20     INFO -  1600232900413	Marionette	DEBUG	16 -> [0,12,"WebDriver:GetWindowHandles",{}]
[task 2020-09-16T05:08:20.435Z] 05:08:20     INFO -  1600232900416	Marionette	DEBUG	16 <- [1,12,null,["16","72"]]
[task 2020-09-16T05:08:20.435Z] 05:08:20     INFO -  1600232900420	Marionette	DEBUG	16 -> [0,13,"WebDriver:SwitchToWindow",{"handle":"72","focus":true}]
[task 2020-09-16T05:08:20.469Z] 05:08:20     INFO -  1600232900436	Marionette	TRACE	Received DOM event TabSelect for [object XULElement]
[task 2020-09-16T05:08:20.470Z] 05:08:20     INFO -  1600232900455	Marionette	DEBUG	16 <- [1,13,null,{"value":null}]
[task 2020-09-16T05:08:20.470Z] 05:08:20     INFO -  1600232900459	Marionette	DEBUG	16 -> [0,14,"WebDriver:GetTimeouts",{}]
[task 2020-09-16T05:08:20.470Z] 05:08:20     INFO -  1600232900459	Marionette	DEBUG	16 <- [1,14,null,{"implicit":0,"pageLoad":300000,"script":30000}]
[task 2020-09-16T05:08:20.505Z] 05:08:20     INFO -  1600232900471	Marionette	DEBUG	16 -> [0,15,"WebDriver:ExecuteScript",{"script":"return window.history.length;","newSandbox":true,"args":[],"filename":"tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py","sandbox":"default","line":72}]
[task 2020-09-16T05:08:20.506Z] 05:08:20     INFO -  1600232900479	Marionette	DEBUG	16 <- [1,15,null,{"value":1}]
[task 2020-09-16T05:08:20.506Z] 05:08:20     INFO -  1600232900482	Marionette	DEBUG	16 -> [0,16,"WebDriver:Navigate",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0 ... 22%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20"}]
[task 2020-09-16T05:08:20.506Z] 05:08:20     INFO -  1600232900489	Marionette	TRACE	Received message beforeunload for about:blank
[task 2020-09-16T05:08:20.515Z] 05:08:20     INFO -  1600232900495	Marionette	TRACE	Received message pagehide for about:blank
[task 2020-09-16T05:08:20.522Z] 05:08:20     INFO -  DEBUG: Adding blocker Transaction (10) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-09-16T05:08:20.541Z] 05:08:20     INFO -  1600232900533	Marionette	TRACE	Received message DOMContentLoaded for data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0A%20%20%20%20%20%20%20%20%20%20%3Ci ... %2522%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20
[task 2020-09-16T05:08:20.556Z] 05:08:20     INFO -  DEBUG: Completed blocker Transaction (10) for phase content-prefs.sqlite#0: waiting for clients
[task 2020-09-16T05:08:20.571Z] 05:08:20     INFO -  1600232900557	Marionette	TRACE	Received message pageshow for data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0A%20%20%20%20%20%20%20%20%20%20%3Ci ... %2522%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20
[task 2020-09-16T05:08:20.572Z] 05:08:20     INFO -  1600232900564	Marionette	DEBUG	16 <- [1,16,null,{"value":null}]
[task 2020-09-16T05:08:20.610Z] 05:08:20     INFO -  1600232900575	Marionette	DEBUG	16 -> [0,17,"WebDriver:FindElement",{"using":"tag name","value":"iframe"}]
[task 2020-09-16T05:08:20.610Z] 05:08:20     INFO -  1600232900589	Marionette	DEBUG	16 <- [1,17,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"4fb326ed-cb0e-1940-900d-4b0f376f78bf"}}]
[task 2020-09-16T05:08:20.610Z] 05:08:20     INFO -  1600232900592	Marionette	DEBUG	16 -> [0,18,"WebDriver:SwitchToFrame",{"focus":true,"element":"4fb326ed-cb0e-1940-900d-4b0f376f78bf"}]
[task 2020-09-16T05:08:20.610Z] 05:08:20     INFO -  1600232900600	Marionette	DEBUG	16 <- [1,18,null,{"value":null}]
[task 2020-09-16T05:08:20.610Z] 05:08:20     INFO -  1600232900602	Marionette	DEBUG	16 -> [0,19,"WebDriver:FindElement",{"using":"tag name","value":"a"}]
[task 2020-09-16T05:08:20.615Z] 05:08:20     INFO -  1600232900609	Marionette	DEBUG	16 <- [1,19,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"24ff92cd-5385-5d4b-9de9-f64016a5f9c6"}}]
[task 2020-09-16T05:08:20.618Z] 05:08:20     INFO -  1600232900613	Marionette	DEBUG	16 -> [0,20,"WebDriver:ElementClick",{"id":"24ff92cd-5385-5d4b-9de9-f64016a5f9c6"}]
[task 2020-09-16T05:08:20.907Z] 05:08:20     INFO -  1600232900873	Marionette	TRACE	Canceled page load listener because no navigation has been detected
[task 2020-09-16T05:08:20.907Z] 05:08:20     INFO -  1600232900873	Marionette	DEBUG	16 <- [1,20,null,{"value":null}]
[task 2020-09-16T05:08:20.908Z] 05:08:20     INFO -  1600232900879	Marionette	DEBUG	16 -> [0,21,"WebDriver:GetCurrentURL",{}]
[task 2020-09-16T05:08:20.943Z] 05:08:20     INFO -  1600232900923	Marionette	DEBUG	16 <- [1,21,null,{"value":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0A%20%20%20%20% ... 22%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20"}]
[task 2020-09-16T05:08:20.943Z] 05:08:20     INFO -  DEBUG: Adding blocker UserInteractionTimer 2 for document 126b31000 for phase xpcom-will-shutdown
[task 2020-09-16T05:08:20.944Z] 05:08:20     INFO -  1600232900941	Marionette	DEBUG	16 -> [0,22,"Marionette:GetContext",{}]
[task 2020-09-16T05:08:20.944Z] 05:08:20     INFO -  1600232900941	Marionette	DEBUG	16 <- [1,22,null,{"value":"content"}]
[task 2020-09-16T05:08:20.968Z] 05:08:20     INFO -  1600232900952	Marionette	DEBUG	16 -> [0,23,"Marionette:SetContext",{"value":"chrome"}]
[task 2020-09-16T05:08:20.968Z] 05:08:20     INFO -  1600232900953	Marionette	DEBUG	16 <- [1,23,null,{"value":null}]
[task 2020-09-16T05:08:20.972Z] 05:08:20     INFO -  1600232900966	Marionette	TRACE	[72] Frame with id 6442450969 got removed
[task 2020-09-16T05:08:21.051Z] 05:08:21     INFO -  1600232901039	Marionette	DEBUG	16 -> [0,24,"WebDriver:TakeScreenshot",{"full":true,"hash":false,"id":null,"scroll":true}]
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - Failed to gather test failure debug: Browsing context has been discarded
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - stacktrace:
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - 	WebDriverError@chrome://marionette/content/error.js:181:5
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - 	NoSuchWindowError@chrome://marionette/content/error.js:415:5
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - 	assert.that/<@chrome://marionette/content/assert.js:460:13
[task 2020-09-16T05:08:21.153Z] 05:08:21  WARNING - 	assert.open@chrome://marionette/content/assert.js:168:4
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	GeckoDriver.prototype.getPageSource@chrome://marionette/content/driver.js:1284:10
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	despatch@chrome://marionette/content/server.js:297:40
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	execute@chrome://marionette/content/server.js:267:16
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	onPacket/<@chrome://marionette/content/server.js:240:20
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	onPacket@chrome://marionette/content/server.js:241:9
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 	_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20
[task 2020-09-16T05:08:21.154Z] 05:08:21  WARNING - 
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO - TEST-UNEXPECTED-FAIL | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestNavigate.test_navigate_top_frame_from_nested_context | AssertionError: u'data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0A%20%20%20%20%20%20%20%20%20%20%3Ciframe%20src%3D%22data%3Atext/html%3Bcharset%3Dutf-8%2C%250A%2520%2520%2520%2520%2520%2520%2520%2520%2520%2520%253Ctitle%253Ebar%253C/title%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%2520%2520%253Ca%2520href%253D%2522http%253A//127.0.0.1%253A50185/test.html%2522%2520target%253D%2522_top%2522%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20' != 'http://127.0.0.1:50185/test.html'
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO - Traceback (most recent call last):
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO -   File "/Users/cltbld/tasks/task_1600232567/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 196, in run
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO -     testMethod()
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO -   File "/Users/cltbld/tasks/task_1600232567/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 182, in test_navigate_top_frame_from_nested_context
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO -     self.assertEqual(self.marionette.get_url(), self.test_page_remote)
[task 2020-09-16T05:08:21.194Z] 05:08:21     INFO - TEST-INFO took 882ms
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901131	Marionette	DEBUG	16 <- [1,24,null,{"value":"iVBORw0KGgoAAAANSUhEUgAABQAAAAQmCAYAAABvZhJoAAAgAElEQVR4nOzdeXRUdZ738fvPnDNbZnqZSaud6Z5hZug20zJtuvGhx7FH ... AAAACMCUAAAAAAGBOAAAAAADAmAAEAAABgTAACAAAAwJgABAAAAIAxAQgAAAAAYwIQAAAAAMYEIAAAAACMCUAAAAAAGAt481VJFhEL9gAAAABJRU5ErkJggg=="}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901135	Marionette	DEBUG	16 -> [0,25,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901136	Marionette	DEBUG	16 <- [1,25,null,{"value":null}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901138	Marionette	DEBUG	16 -> [0,26,"Marionette:GetContext",{}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901138	Marionette	DEBUG	16 <- [1,26,null,{"value":"content"}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901139	Marionette	DEBUG	16 -> [0,27,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901140	Marionette	DEBUG	16 <- [1,27,null,{"value":null}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901141	Marionette	DEBUG	16 -> [0,28,"WebDriver:GetPageSource",{}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901141	Marionette	DEBUG	16 <- [1,28,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"WebDriverError@chrome://marione ... t@chrome://marionette/content/server.js:241:9\n_onJSONObjectReady/<@chrome://marionette/content/transport.js:504:20\n"},null]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901143	Marionette	DEBUG	16 -> [0,29,"Marionette:SetContext",{"value":"content"}]
[task 2020-09-16T05:08:21.195Z] 05:08:21     INFO -  1600232901143	Marionette	DEBUG	16 <- [1,29,null,{"value":null}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901148	Marionette	DEBUG	16 -> [0,30,"WebDriver:SetTimeouts",{"script":30000}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901149	Marionette	DEBUG	16 <- [1,30,null,{"value":null}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901152	Marionette	DEBUG	16 -> [0,31,"WebDriver:SetTimeouts",{"pageLoad":300000}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901153	Marionette	DEBUG	16 <- [1,31,null,{"value":null}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901157	Marionette	DEBUG	16 -> [0,32,"WebDriver:SetTimeouts",{"implicit":0}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901157	Marionette	DEBUG	16 <- [1,32,null,{"value":null}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901158	Marionette	DEBUG	16 -> [0,33,"WebDriver:GetWindowHandles",{}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901159	Marionette	DEBUG	16 <- [1,33,null,["16","72"]]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901161	Marionette	DEBUG	16 -> [0,34,"WebDriver:SwitchToWindow",{"handle":"72","focus":true}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901162	Marionette	DEBUG	16 <- [1,34,null,{"value":null}]
[task 2020-09-16T05:08:21.196Z] 05:08:21     INFO -  1600232901163	Marionette	DEBUG	16 -> [0,35,"WebDriver:CloseWindow",{}]
[task 2020-09-16T05:08:21.197Z] 05:08:21     INFO -  1600232901177	Marionette	TRACE	Received DOM event TabClose for [object XULElement]
[task 2020-09-16T05:08:21.197Z] 05:08:21     INFO -  1600232901177	Marionette	TRACE	Received DOM event TabClose for [object XULElement]
[task 2020-09-16T05:08:21.197Z] 05:08:21     INFO -  1600232901185	Marionette	TRACE	[72] Frame script unloaded
[task 2020-09-16T05:08:21.197Z] 05:08:21     INFO -  JavaScript error: chrome://marionette/content/listener.js, line 1321: TypeError: can't access dead object```

Here the real failure:

[task 2020-09-16T05:08:20.618Z] 05:08:20     INFO -  1600232900613	Marionette	DEBUG	16 -> [0,20,"WebDriver:ElementClick",{"id":"24ff92cd-5385-5d4b-9de9-f64016a5f9c6"}]
[task 2020-09-16T05:08:20.907Z] 05:08:20     INFO -  1600232900873	Marionette	TRACE	Canceled page load listener because no navigation has been detected
[task 2020-09-16T05:08:20.907Z] 05:08:20     INFO -  1600232900873	Marionette	DEBUG	16 <- [1,20,null,{"value":null}]
[task 2020-09-16T05:08:20.908Z] 05:08:20     INFO -  1600232900879	Marionette	DEBUG	16 -> [0,21,"WebDriver:GetCurrentURL",{}]
[task 2020-09-16T05:08:20.943Z] 05:08:20     INFO -  1600232900923	Marionette	DEBUG	16 <- [1,21,null,{"value":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Ctitle%3Efoo%3C/title%3E%0A%20%20%20%20% ... 22%253Econsume%2520top%2520frame%253C/a%253E%250A%2520%2520%2520%2520%2520%2520%2520%2520%22%3E%0A%20%20%20%20%20%20%20%20"}]

Similar to bug 1665210 but for non-fission and only intermittently failing.

The problem here seems to be with the test. While the sub frame is currently selected, the navigation happens in the top frame. But these navigation events aren't checked (as I also get that from the WebDriver spec). Also given that the current browsing context gets destroyed, we return immediately and don't await the navigation to be finished in the top-level browsing context.

I believe that in this case we actually need a custom check for the navigation to be done by awaiting the expected URL.

Blocks: 1665210

Given that this also includes a perma-failure for Fission (see bug 1665210) I will tag is for our Fission work. I will leave the other bug open for general Fission tracking purposes.

Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Whiteboard: [marionette-fission-mvp][simple]

If a click triggers a navigation in the top-browsing context from
inside a frame, the frame gets removed and as such the "Element Click"
command immediately returns. As such waiting for the navigation to
be finished has to be taken care of by the test itself.

Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/41f288d47a65
[marionette] Wait for the expected URL when navigation starts from inside a frame. r=marionette-reviewers,maja_zf

https://hg.mozilla.org/mozilla-central/rev/41f288d47a65

Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox83: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 83 Branch

Ricky, Alert 27062 releals in the graph (zoom here) that this bug caused the regression. The patch looks harmless though. The regression is obvious if we look at the graph from the 14 days timerange but not so obvious if we look from the 30 days timerange. At the beginning of september it was over 2900, it improved slowly and around sept 22 it seems be regressed again.
Could you please take a look?

Flags: needinfo?(rstewart)

The regression you're pointing to looks more like bug 1666525 to me. I zoomed in and I don't see that pointing at this bug as the cause of the regression makes sense. But bug 1666525 is just upgrading from Clang 11rc2 to rc3, and I doubt that that much of a performance regression popped up between the two release candidates. dmajor, does that read to you? Or do you have a better guess for what the cause of the regression is?

Flags: needinfo?(rstewart) → needinfo?(dmajor)

One of the challenging things about our build time reporting is that we have many different builder types and they are assigned (AFAICT) at random. I see that the sheriffs triggered 5-6 builds on surrounding changesets, but that's usually not enough in my experience. Ideally we'd have multiple data points per machine type. If there's a way to request a specific machine, that'd be great, otherwise the only solution I can think of is to trigger like 25 rebuilds per suspect changeset.

Flags: needinfo?(dmajor)
See Also: → 1669957

The regression seems to be pointing straight at the Update to clang 11.0.0 rc3. The graph is unclear between 9f3604e327fe8 and 3c1b9452c0e63 but giving that 3c1b9452c0e63 adds just a comment to the code, we only have 9f3604e327fe8 left.

Let's move the build time discussion to bug 1669957 and/or bug 1670177, since this isn't about marionette intermittents anymore.

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.

Attachment

General

Creator:
Created:
Updated:
Size: