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)
Tracking
(firefox65 fixed)
RESOLVED
FIXED
mozilla65
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
Assignee | ||
Comment 1•6 years ago
|
||
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)
Comment 2•6 years ago
|
||
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)
Assignee | ||
Comment 3•6 years ago
|
||
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.
Assignee | ||
Comment 4•6 years ago
|
||
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)
Comment 5•6 years ago
|
||
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)
Assignee | ||
Comment 6•6 years ago
|
||
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.
Assignee | ||
Comment 7•6 years ago
|
||
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.
Assignee | ||
Comment 8•6 years ago
|
||
needinfo Olli again because he might have missd the last two comments.
Flags: needinfo?(bugs)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 12•6 years ago
|
||
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)
Assignee | ||
Comment 13•6 years ago
|
||
(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.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 17•6 years ago
|
||
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.
Assignee | ||
Comment 18•6 years ago
|
||
We should actually already be able to fix this problem by turning off `about:newtab` by default (bug 1506643).
Depends on: 1506643
Assignee | ||
Comment 19•6 years ago
|
||
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
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 21•6 years ago
|
||
Adding `[stockwell disable-recommended]` for an already fixed bug seems to be a bug in the OF commenter, or?
Flags: needinfo?(sclements)
Comment 22•6 years ago
|
||
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)
Updated•2 years ago
|
Product: Testing → Remote Protocol
Comment 23•2 years ago
|
||
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.
Description
•