Closed Bug 1666755 Opened 4 years ago Closed 4 years ago

Wait for navigation for WebDriver:ElementClick has to take click delays into account

Categories

(Remote Protocol :: Marionette, defect, P1)

Default
defect

Tracking

(Fission Milestone:M7, firefox-esr78 unaffected, firefox81 unaffected, firefox82 fixed, firefox83 fixed)

RESOLVED FIXED
83 Branch
Fission Milestone M7
Tracking Status
firefox-esr78 --- unaffected
firefox81 --- unaffected
firefox82 --- fixed
firefox83 --- fixed

People

(Reporter: whimboo, Assigned: whimboo)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: regression, Whiteboard: [marionette-fission-mvp][simple])

Attachments

(1 file, 2 obsolete files)

As identified on bug 1394354 comment 19 and ff. there can be a race when synthesizing the click is delayed by some unknown behavior of Firefox. Under such circumstances the already started navigation check will timeout after 200ms because no beforeunload event has been fired yet, and as such the command returns too early.

We have to find a better way to wait with the beforeunload timer until a certain state has been reached, or event received.

With the fix on bug 1394354 this shouldn't be of high priority for now.

Especially for Fission this fails a lot. Here an example from the wdspec tests:

[task 2020-10-09T11:50:15.202Z] 11:50:15     INFO - PID 19525 | 1602244215199	Marionette	DEBUG	0 -> [0,36,"WebDriver:ElementClick",{"id":"a2a52e43-1b1f-4b95-b4bc-11e44f3c5809"}]
[task 2020-10-09T11:50:15.218Z] 11:50:15     INFO - PID 19525 | 1602244215212	Marionette	TRACE	[38] Frame with id 10737418242 got removed
[task 2020-10-09T11:50:15.218Z] 11:50:15     INFO - PID 19525 | 1602244215212	Marionette	TRACE	Canceled page load listener because current frame has been removed
[task 2020-10-09T11:50:15.218Z] 11:50:15     INFO - PID 19525 | 1602244215212	Marionette	DEBUG	0 <- [1,36,null,{"value":null}]
[task 2020-10-09T11:50:15.219Z] 11:50:15     INFO - PID 19525 | 1602244215213	webdriver::server	DEBUG	<- 200 OK {"value":null}
[task 2020-10-09T11:50:15.219Z] 11:50:15     INFO - PID 19525 | 1602244215214	webdriver::server	DEBUG	-> GET /session/67928302-83b5-4e92-928d-bce83f278d24/element/foo/css/bar
[task 2020-10-09T11:50:15.221Z] 11:50:15     INFO - PID 19525 | 1602244215214	Marionette	DEBUG	0 -> [0,37,"WebDriver:GetElementCSSValue",{"id":"foo","propertyName":"bar"}]
[task 2020-10-09T11:50:15.221Z] 11:50:15     INFO - PID 19525 | 1602244215217	Marionette	TRACE	Received DOM event click for [object HTMLInputElement]
[task 2020-10-09T11:50:15.225Z] 11:50:15     INFO - PID 19525 | 1602244215219	Marionette	DEBUG	0 <- [1,37,{"error":"no such element","message":"Web element reference not seen before: foo","stacktrace":"WebDriverError@chrome:/ ... ch/</req<@chrome://marionette/content/listener.js:101:29\ndispatch/<@chrome://marionette/content/listener.js:100:15\n"},null]
[task 2020-10-09T11:50:15.226Z] 11:50:15     INFO - PID 19525 | 1602244215219	webdriver::server	DEBUG	<- 404 Not Found {"value":{"error":"no such element","message":"Web element reference not seen before: foo","stacktrace":"WebDriverError@chrome://marionette/content/error.js:181:5\nNoSuchElementError@chrome://marionette/content/error.js:393:5\nget@chrome://marionette/content/element.js:225:13\nevaluate.fromJSON@chrome://marionette/content/evaluate.js:242:26\nevaluate.fromJSON/<@chrome://marionette/content/evaluate.js:224:38\nevaluate.fromJSON@chrome://marionette/content/evaluate.js:224:20\ndispatch/</req<@chrome://marionette/content/listener.js:101:29\ndispatch/<@chrome://marionette/content/listener.js:100:15\n"}}
[task 2020-10-09T11:50:15.226Z] 11:50:15     INFO - PID 19525 | DEBUG: Adding blocker UserInteractionTimer 1 for document 7f501f7fa000 for phase xpcom-will-shutdown
Priority: P3 → P2
Whiteboard: [marionette-fission-mvp]

Ok, this is so silly. We indeed do not have to setup the beforeunload timer before we actually click the element. Internally we store seenBeforeUnload and evaluate it within onTimer, which means we can safely move its initialization to after the click event has happened.

Assignee: nobody → hskupin
Status: NEW → ASSIGNED
Priority: P2 → P1

Due to delays when the click and the appropriate event will actually
happen within the child process, the beforeunload timer with 200ms
timeout needs to be run after the click event has been received.

From user reports this might actually be the most common failure with the WebDriver:ClickElement command, and as such I would really like to see it fixed in the 82 release. So lets see how the patch works out on try, given that it fails a lot for Fission enabled test jobs.

Whiteboard: [marionette-fission-mvp] → [marionette-fission-mvp][simple]

Websites can prevent the propagation of click events in case of
further processing of the input. If that is the case flushEventLoop
has to wait for the click event that has not been prevented.

Depends on D93194

Tracking marionette-fission-mvp bugs for Fission Beta milestone (M7)

Fission Milestone: --- → M7
Attachment #9181031 - Attachment is obsolete: true
Attachment #9181103 - Attachment is obsolete: true
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/d634a4106356
[marionette] Run beforeunload timer after the click event has been received. r=marionette-reviewers,jdescottes
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → 83 Branch

This is actually a regression from bug 1612831, and as such affects Firefox 82.

Keywords: regression
Regressed by: 1612831

Comment on attachment 9180974 [details]
Bug 1666755 - [marionette] Run beforeunload timer after the click event has been received.

Beta/Release Uplift Approval Request

  • User impact if declined: The WebDriver command Element Click could return too early if synthesizing the click event is delayed due to some IPC overhead, which will happen more often when the browser is under load when running test automation. As such the click happens when one of the next commands are executed and trigger a race condition causing tests to fail.
  • Is this code covered by automated tests?: Yes
  • Has the fix been verified in Nightly?: Yes
  • Needs manual test from QE?: No
  • If yes, steps to reproduce:
  • List of other uplifts needed: None
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): Moving the initialization of the timeout from before to after the click event listener.
  • String changes made/needed: None
Attachment #9180974 - Flags: approval-mozilla-beta?

Comment on attachment 9180974 [details]
Bug 1666755 - [marionette] Run beforeunload timer after the click event has been received.

we've already built release candidates for 82, it seems too late for this, sorry.

Attachment #9180974 - Flags: approval-mozilla-beta? → approval-mozilla-beta-

(In reply to Julien Cristau [:jcristau] from comment #13)

we've already built release candidates for 82, it seems too late for this, sorry.

Any chance to pick that in case another release candidate has to be built?

Flags: needinfo?(jcristau)

Unlikely, for a bug that's S3...

Flags: needinfo?(jcristau)

(In reply to Julien Cristau [:jcristau] from comment #15)

Unlikely, for a bug that's S3...

Well, that's what I missed to update. Sorry about that. Usually we got pinged in the past when a branch was marked as affected but no patch has been landed yet. It would be nice to have someone doing that, or some automation you run maybe a week before the release candidates.

There is basically no workaround for tools / harnesses using geckodriver. Test's can't simply call Element Click again given that the action might have already taken place, and the element is not available anymore. Also in several test suites the calls to element click would have to be followed by a page load or status checks. We cannot force users to do that in their test suites.

So please re-consider this bug when there is another RC.

Severity: S3 → S2
Flags: needinfo?(jcristau)

I don't think we have such automation (that would be pretty noisy), but also a week before release candidates this bug wasn't marked as a regression, or as affecting 82.

Flags: needinfo?(jcristau)

Comment on attachment 9180974 [details]
Bug 1666755 - [marionette] Run beforeunload timer after the click event has been received.

approved for 82.0.1

Attachment #9180974 - Flags: approval-mozilla-release+
Product: Testing → Remote Protocol
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: