New window command can timeout because opened window doesn't always receive the focus even with `focus` event emitted
Categories
(Remote Protocol :: Marionette, defect, P2)
Tracking
(firefox67 fixed)
Tracking | Status | |
---|---|---|
firefox67 | --- | fixed |
People
(Reporter: whimboo, Assigned: whimboo)
References
Details
Attachments
(2 files)
(deleted),
patch
|
ato
:
review+
|
Details | Diff | Splinter Review |
(deleted),
text/x-phabricator-request
|
Details |
Here an example for bug 1521563:
[task 2019-01-21T15:03:22.070Z] 15:03:22 INFO - 1548083002060 Marionette DEBUG 70 -> [0,12,"WebDriver:NewWindow",{"type":"window","focus":false}]
[task 2019-01-21T15:03:22.107Z] 15:03:22 INFO - 1548083002103 Marionette TRACE Received DOM event activate for [object ChromeWindow]
[task 2019-01-21T15:03:22.109Z] 15:03:22 INFO - 1548083002103 Marionette TRACE Received DOM event focus for [object XULDocument]
[task 2019-01-21T15:03:22.268Z] 15:03:22 INFO - 1548083002255 Marionette TRACE Received observer notification browser-delayed-startup-finished
[task 2019-01-21T15:09:22.143Z] 15:09:22 INFO - 1548083362137 Marionette DEBUG Closed connection 70
Updated•6 years ago
|
Assignee | ||
Comment 1•6 years ago
|
||
I would suggest that we land some debug code for this method so that we can check what's actually going wrong here. The failure is low intermittent and I wasn't able to reproduce it yet.
Assignee | ||
Comment 2•6 years ago
|
||
Assignee | ||
Comment 3•6 years ago
|
||
Assignee | ||
Comment 4•6 years ago
|
||
Comment on attachment 9044710 [details] [diff] [review] [marionette] Add debug output for handling focus in "WebDriver:NewWindow" Adds tracing output for focus selection after new window has been opened.
Assignee | ||
Comment 5•6 years ago
|
||
Note that I was not able to catch this failure in all of the try build's Mn jobs, which retriggered a dozen of times. With landing the debug output patch I hope to get a better idea what's going wrong.
Assignee | ||
Updated•6 years ago
|
Comment 6•6 years ago
|
||
Comment on attachment 9044710 [details] [diff] [review] [marionette] Add debug output for handling focus in "WebDriver:NewWindow" Review of attachment 9044710 [details] [diff] [review]: ----------------------------------------------------------------- ::: testing/marionette/browser.js @@ +337,5 @@ > activated = waitForEvent(this.window, "activate"); > focused = waitForEvent(this.window, "focus", {capture: true}); > > + logger.trace("Setting focus back to opening window " + > + ` due to focus: ${focus}`); Space at end of previous string and at beginning of this, makes a total of two spaces.
Assignee | ||
Updated•6 years ago
|
Assignee | ||
Comment 7•6 years ago
|
||
(In reply to Andreas Tolfsen ⦗:ato⦘ from comment #6)
activated = waitForEvent(this.window, "activate"); focused = waitForEvent(this.window, "focus", {capture: true});
logger.trace("Setting focus back to opening window " +
` due to focus: ${focus}`);
Space at end of previous string and at beginning of this, makes a
total of two spaces.
Ups. I will fix it before pushing to inbound. Thanks.
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/e18dc4b5dc31 [marionette] Add debug output for handling focus in "WebDriver:NewWindow". r=ato
Assignee | ||
Updated•6 years ago
|
Comment 9•6 years ago
|
||
bugherder |
Assignee | ||
Comment 10•6 years ago
|
||
The debug information which was landed earlier last week was pretty helpful. Here the details:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=230185698&repo=autoland&lineNumber=24544
[task 2019-02-24T21:18:49.262Z] 21:18:49 INFO - 1551043129259 Marionette DEBUG 71 -> [0,12,"WebDriver:NewWindow",{"type":"window","focus":false}]
[task 2019-02-24T21:18:49.344Z] 21:18:49 INFO - 1551043129342 Marionette TRACE Received DOM event activate for [object ChromeWindow]
[task 2019-02-24T21:18:49.345Z] 21:18:49 INFO - 1551043129342 Marionette TRACE Received DOM event focus for [object XULDocument]
[task 2019-02-24T21:18:49.515Z] 21:18:49 INFO - 1551043129512 Marionette TRACE Received observer notification browser-delayed-startup-finished
[task 2019-02-24T21:18:49.523Z] 21:18:49 INFO - 1551043129517 Marionette TRACE Opening window is active window: true
[task 2019-02-24T21:18:49.524Z] 21:18:49 INFO - 1551043129519 Marionette TRACE Setting focus back to opening window due to focus: false
It means that the newly opened browser window gets the activate
and focus
event, but doesn't actually have the focus. Instead the opening window keeps the focus, maybe only for a few number of milliseconds but it's enough to cause a race, when we are trying to focus it again and waiting for the focus
and activate
events.
Neil, is a behavior like that known? Maybe it is focus manager test mode related? Btw. the intermittent rate is low.
Assignee | ||
Updated•6 years ago
|
Comment 11•6 years ago
|
||
Genarally, most focus problems like this happen on GTK as it tends to send asynchronous focus notifications and problems arise when windows are opened/closed/focused in quick succession.
Are you sure that the focus happening after the timeout is occuring? See https://searchfox.org/mozilla-central/source/testing/marionette/browser.js#328
As a side note, the focus event always fires after the activate event, so there isn't any particular reason to wait for the activate event as well.
Assignee | ||
Comment 12•6 years ago
|
||
(In reply to Neil Deakin from comment #11)
Genarally, most focus problems like this happen on GTK as it tends to send asynchronous focus notifications and problems arise when windows are opened/closed/focused in quick succession.
Are you sure that the focus happening after the timeout is occuring? See https://searchfox.org/mozilla-central/source/testing/marionette/browser.js#328
When you check the log output from comment 10 we clearly get the activate
and focus
events, as setup via a Promise before. So the call to focus()
should have happened. Also could this ever fail? It would be nice to remove the setTimeout
but I cannot do it due to bug 1509234.
As a side note, the focus event always fires after the activate event, so there isn't any particular reason to wait for the activate event as well.
That is what Gijs told me, and which seem to be heavily used for mochitests. If that is the case it could be a larger change.
Assignee | ||
Updated•6 years ago
|
Assignee | ||
Comment 13•6 years ago
|
||
I will go ahead and just add the check if the original window hasn't the focus yet. Only then really call focus()
.
try build:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a543adbeee12494e9fcfc7fb3fce2ef0dd6d626d
Assignee | ||
Comment 14•6 years ago
|
||
Comment 15•6 years ago
|
||
Pushed by hskupin@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2b18f28016cf [marionette] Only focus target window if it isn't already the active window. r=ato
Comment 16•6 years ago
|
||
bugherder |
Assignee | ||
Updated•6 years ago
|
Updated•2 years ago
|
Description
•