Closed Bug 1503027 Opened 6 years ago Closed 6 years ago

Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_window_close_content.py TestCloseWindow.test_close_window_with_dismissed_beforeunload_prompt | NoSuchElementException: Unable to locate element: input

Categories

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

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

Tracking

(firefox65 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla65
Tracking Flags:
Tracking Status
firefox65 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disable-recommended])

Filed by: ncsoregi [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=208465350&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/baWYdG2BRZCwntnWgzbsPA/runs/0/artifacts/public/logs/live_backing.log [task 2018-10-29T20:36:33.489Z] 20:36:33 INFO - 1540845393482 Marionette TRACE 96 <- [1,25,null,{"value":null}] [task 2018-10-29T20:36:33.491Z] 20:36:33 INFO - 1540845393483 Marionette TRACE 96 -> [0,26,"WebDriver:GetPageSource",{}] [task 2018-10-29T20:36:33.514Z] 20:36:33 INFO - 1540845393511 Marionette TRACE 96 <- [1,26,null,{"value":"<html><head></head><body><input type=\"text\">\n <script>\n window.addEventListener( ... ", function (event) {\n event.preventDefault();\n });\n </script>\n </body></html>"}] [task 2018-10-29T20:36:33.516Z] 20:36:33 INFO - 1540845393513 Marionette TRACE 96 -> [0,27,"Marionette:SetContext",{"value":"content"}] [task 2018-10-29T20:36:33.520Z] 20:36:33 INFO - 1540845393513 Marionette TRACE 96 <- [1,27,null,{"value":null}] [task 2018-10-29T20:36:33.551Z] 20:36:33 INFO - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_window_close_content.py TestCloseWindow.test_close_window_with_dismissed_beforeunload_prompt | NoSuchElementException: Unable to locate element: input [task 2018-10-29T20:36:33.552Z] 20:36:33 INFO - stacktrace: [task 2018-10-29T20:36:33.554Z] 20:36:33 INFO - WebDriverError@chrome://marionette/content/error.js:178:5 [task 2018-10-29T20:36:33.557Z] 20:36:33 INFO - NoSuchElementError@chrome://marionette/content/error.js:388:5 [task 2018-10-29T20:36:33.559Z] 20:36:33 INFO - element.find/</<@chrome://marionette/content/element.js:339:16 [task 2018-10-29T20:36:33.561Z] 20:36:33 INFO - MessageListener.receiveMessage*startListeners@chrome://marionette/content/listener.js:530:3 [task 2018-10-29T20:36:33.563Z] 20:36:33 INFO - registerSelf@chrome://marionette/content/listener.js:458:5 [task 2018-10-29T20:36:33.566Z] 20:36:33 INFO - @chrome://marionette/content/listener.js:1679:1 [task 2018-10-29T20:36:33.568Z] 20:36:33 INFO - Traceback (most recent call last): [task 2018-10-29T20:36:33.569Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run [task 2018-10-29T20:36:33.571Z] 20:36:33 INFO - testMethod() [task 2018-10-29T20:36:33.572Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/decorators.py", line 152, in skip_wrapper [task 2018-10-29T20:36:33.574Z] 20:36:33 INFO - return test_item(self, *args, **kwargs) [task 2018-10-29T20:36:33.576Z] 20:36:33 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_window_close_content.py", line 88, in test_close_window_with_dismissed_beforeunload_prompt [task 2018-10-29T20:36:33.578Z] 20:36:33 INFO - self.marionette.find_element(By.TAG_NAME, "input").send_keys("foo") [task 2018-10-29T20:36:33.580Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 1839, in find_element [task 2018-10-29T20:36:33.581Z] 20:36:33 INFO - body, key="value") [task 2018-10-29T20:36:33.583Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/decorators.py", line 26, in _ [task 2018-10-29T20:36:33.584Z] 20:36:33 INFO - return func(*args, **kwargs) [task 2018-10-29T20:36:33.586Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 764, in _send_message [task 2018-10-29T20:36:33.589Z] 20:36:33 INFO - self._handle_error(err) [task 2018-10-29T20:36:33.590Z] 20:36:33 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/marionette.py", line 784, in _handle_error [task 2018-10-29T20:36:33.592Z] 20:36:33 INFO - raise errors.lookup(error)(message, stacktrace=stacktrace) [task 2018-10-29T20:36:33.593Z] 20:36:33 INFO - TEST-INFO took 634ms
After the page load no content is shown in the tab, which blocks any interaction with the DOM. Andreas, you mentioned that you have a bug number for that. Can you please tell it to us? Thanks.
Flags: needinfo?(ato)
I’ve experienced https://bugzilla.mozilla.org/show_bug.cgi?id=1415923 locally on macOS, but I suppose locking the screen/switching users is not the same thing as this bug, since it happens in a much shorter timespan…
Flags: needinfo?(ato)
Depends on: 1503274
Correct, that is most likely unrelated. Actually when checking the trace log again, this is interesting: > [task 2018-10-29T20:36:33.143Z] 20:36:33 INFO - 1540845393129 Marionette TRACE 96 -> [0,18,"WebDriver:Navigate",{"url":"data:text/html;charset=utf-8,%0A%20%20%20%20%20%20%20%20%20%20%3Cinput%20type%3D%22text%22 ... B%0A%20%20%20%20%20%20%20%20%20%20%20%20%7D%29%3B%0A%20%20%20%20%20%20%20%20%20%20%3C/script%3E%0A%20%20%20%20%20%20%20%20"}] > [task 2018-10-29T20:36:33.145Z] 20:36:33 INFO - 1540845393139 Marionette DEBUG [8589934605] Frame script loaded > [task 2018-10-29T20:36:33.147Z] 20:36:33 INFO - 1540845393142 Marionette DEBUG [8589934605] Frame script registered > [task 2018-10-29T20:36:33.165Z] 20:36:33 INFO - 1540845393153 Marionette DEBUG [8589934608] Frame script loaded > [task 2018-10-29T20:36:33.167Z] 20:36:33 INFO - 1540845393153 Marionette DEBUG [8589934608] Frame script registered > [task 2018-10-29T20:36:33.207Z] 20:36:33 INFO - 1540845393202 Marionette DEBUG [8589934605] Received DOM event beforeunload for about:newtab > [task 2018-10-29T20:36:33.228Z] 20:36:33 INFO - 1540845393219 Marionette DEBUG [8589934605] Check readyState complete for about:newtab > [task 2018-10-29T20:36:33.244Z] 20:36:33 INFO - 1540845393239 Marionette TRACE 96 <- [1,18,null,{"value":null}] > [task 2018-10-29T20:36:33.260Z] 20:36:33 INFO - 1540845393249 Marionette TRACE 96 -> [0,19,"WebDriver:FindElement",{"using":"tag name","value":"input"}] > [task 2018-10-29T20:36:33.309Z] 20:36:33 INFO - 1540845393303 Marionette TRACE 96 <- [1,19,{"error":"no such element","message":"Unable to locate element: input","stacktrace":"WebDriverError@chrome://marionette ... :530:3\nregisterSelf@chrome://marionette/content/listener.js:458:5\n@chrome://marionette/content/listener.js:1679:1\n"},null] The frame script gets reloaded twice! And as it looks like the original navigation request is forgotten, and instead `about:newtab` has been loaded. I wonder how this is triggered.
Olli, do you know under which conditions a frame script could be reloaded twice after triggering a navigation? In this case it was just a data URL (and not a file URL where I would expect a reload).
Flags: needinfo?(bugs)
frame script shouldn't be loaded twice to a same tab child global. What does the number mean in the log before 'Frame script loaded'?
Flags: needinfo?(bugs)
This is the outer window id which we use to identify the content window (frame script). But that's interesting through: https://treeherder.mozilla.org/logviewer.html#?job_id=208465350&repo=mozilla-inbound&lineNumber=27130-27140 We switch to window 8589934605, and trigger the page load in that window. Then temporarily we see the frame script loaded/registered message for the window with the id 8589934608. Afterward the page load is performed for window with id 8589934605, but not for the requested page. Instead `about:newtab` gets loaded.
Btw if the wording of this log message is wrong, I would appreciate a proposal to improve it. It comes from here: https://dxr.mozilla.org/mozilla-central/source/testing/marionette/listener.js#440 It's basically run when the frame script gets loaded, and then every time when the process changes.
needinfo Olli again because he might have missd the last two comments.
Flags: needinfo?(bugs)
So we do see frame script loaded only once per tab. Do we somehow end up loading testcase on a wrong tab?
Flags: needinfo?(bugs)
Depends on: 1504807
(In reply to Olli Pettay [:smaug] (high review load) from comment #12) > So we do see frame script loaded only once per tab. It's loaded only once, but it gets moved to a different process twice. I just filed bug 1504807 for Marionette, which should fix that.
This is really an overlap between loading `about:newtab` after opening a new browser tab, and a through Marionette triggered page load. So it depends on bug 1503274.
We should actually already be able to fix this problem by turning off `about:newtab` by default (bug 1506643).
Depends on: 1506643
Indeed. There are no more failures in integration branches since this patch landed.
Assignee: nobody → hskupin
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox65: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
Adding `[stockwell disable-recommended]` for an already fixed bug seems to be a bug in the OF commenter, or?
Flags: needinfo?(sclements)
It doesn't look like we've ever fetched a bug's `status` or `resolution` in the Commenter (even looking back into the Orange Factor code). Instead it relies on checking whiteboard text for any of these strings: 'fixed', 'disabled', 'disable-recommended', 'infra' before the whiteboard is ever changed. If you want it to also check `resolution` or `status` could you please file a bug?
Flags: needinfo?(sclements)
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.