Closed Bug 1360466 Opened 7 years ago Closed 7 years ago

Intermittent test_click.py TestClickNavigation.test_click_remoteness_change | IOError: Process killed because the connection to Marionette server is lost. Check gecko.log for errors (Reason: Connection timed out after 360.0s)

Categories

(Testing :: Marionette Client and Harness, defect)

Version 3
defect
Not set
normal

Tracking

(firefox54 fixed, firefox55 fixed)

RESOLVED FIXED
mozilla55
Tracking Status
firefox54 --- fixed
firefox55 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

Problem here is an unexpected reload of the frame script within findElement:

1493327293538	Marionette	TRACE	440 -> [0,20,"clickElement",{"id":"9fe3453d-ba99-44e2-ac5e-1566e115485b"}]
1493327293836	Marionette	DEBUG	Received DOM event "hashchange" for "undefined"
1493327293864	Marionette	TRACE	440 <- [1,20,null,{}]
1493327293887	Marionette	TRACE	440 -> [0,21,"findElement",{"using":"id","value":"anchor"}]
++DOCSHELL 0000002D3C5EA800 == 7 [pid = 3380] [id = {f878d8a8-f5ed-4ae3-82cf-fb3c49faf1a7}]
++DOMWINDOW == 19 (0000002D47A0D800) [pid = 3380] [serial = 30] [outer = 0000000000000000]
++DOMWINDOW == 20 (0000002D47A17000) [pid = 3380] [serial = 31] [outer = 0000002D47A0D800]
1493327293931	Marionette	DEBUG	loaded listener.js

As we know this will cause a hang as long as bug 1347458 hasn't been fixed.
Depends on: 1347458
Whereby the suspicious entry here is:

1493327293538	Marionette	TRACE	440 -> [0,20,"clickElement",{"id":"9fe3453d-ba99-44e2-ac5e-1566e115485b"}]
1493327293836	Marionette	DEBUG	Received DOM event "hashchange" for "undefined"

Looks like that we have to ensure to handle `hashchange` only if it is related to the current window. If we do so, the call to `clickElement` will not return early, and as such we would not run into `findElement` hanging due to a remoteness change.
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
So I added code to not handle the hashchange even in the case if no target document is set by the event. As result we get:

1493381003528	Marionette	TRACE	6 -> [0,20,"clickElement",{"id":"2919ec6d-6bf0-0f44-90c6-87a0a790f2a6"}]
1493381003737	Marionette	DEBUG	Received DOM event "hashchange" for "undefined"
1493381003761	Marionette	DEBUG	loaded listener.js
1493381003765	Marionette	DEBUG	Received DOM event "pagehide" for "http://127.0.0.1:59066/clicks.html#"
1493381003765	Marionette	DEBUG	Received DOM event "unload" for "http://127.0.0.1:59066/clicks.html#"
1493381003770	Marionette	DEBUG	Received observer notification "outer-window-destroyed" for "6442450948"
1493381003773	Marionette	DEBUG	Received observer notification "outer-window-destroyed" for "6442450949"
1493381003775	Marionette	DEBUG	Received observer notification "outer-window-destroyed" for "6442450945"
1493381003974	Marionette	DEBUG	Received DOM event "DOMContentLoaded" for "about:robots"
1493381004003	Marionette	DEBUG	Received DOM event "pageshow" for "about:robots"
1493381004024	Marionette	TRACE	6 <- [1,20,null,{}]
1493381004029	Marionette	TRACE	6 -> [0,21,"findElement",{"using":"id","value":"anchor"}]
1493381004041	Marionette	TRACE	6 <- [1,21,{"error":"no such element","message":"Unable to locate element: [..]

So the hashchange event is fired because of the click onto the link with the target `history.back()`. If I do this manually, I can see that indeed a hash gets added to the URL. So escaping the page load at this time is not appropriate. Instead waiting for the correct events to appear, the hang can no longer be seen locally.
Comment on attachment 8862820 [details]
Bug 1360466 - Only handle hashchange event for the current window.

https://reviewboard.mozilla.org/r/134744/#review137644
Attachment #8862820 - Flags: review?(ato) → review+
Comment on attachment 8862820 [details]
Bug 1360466 - Only handle hashchange event for the current window.

https://reviewboard.mozilla.org/r/134744/#review137684

::: testing/marionette/listener.js:230
(Diff revision 1)
>            addEventListener("pageshow", this, false);
>          }
>          break;
>  
>        case "hashchange":
> +        if (event.originalTarget === curContainer.frame.document) {

Sadly this cannot land as it is. The try shows perma failures for the backward and forward navigation tests. There might be something we are doing wrong here.
Interestingly we get the 'undefined' output for the document location because we are using `originalTarget` in all the cases. That's something which I simply took over when reworking the page load algorithm. But as the documentation for all the DOM events shows, we should use `event.target` to access the window:

https://developer.mozilla.org/en-US/docs/Web/API/HashChangeEvent
Attachment #8862894 - Flags: review?(ato)
Comment on attachment 8862894 [details]
Bug 1360466 - Use target instead of originalTarget in handleEvent.

https://reviewboard.mozilla.org/r/134774/#review137720
Attachment #8862894 - Flags: review?(ato) → review+
Comment on attachment 8862820 [details]
Bug 1360466 - Only handle hashchange event for the current window.

https://reviewboard.mozilla.org/r/134744/#review137684

> Sadly this cannot land as it is. The try shows perma failures for the backward and forward navigation tests. There might be something we are doing wrong here.

Did the patch to s/originalTarget/target/ fix this?
Comment on attachment 8862820 [details]
Bug 1360466 - Only handle hashchange event for the current window.

https://reviewboard.mozilla.org/r/134744/#review137684

> Did the patch to s/originalTarget/target/ fix this?

Yes, the current try run as referenced in this mozreview request is completely green. So this was the missing piece.
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/7b2de127cc03
Use target instead of originalTarget in handleEvent. r=ato
https://hg.mozilla.org/integration/autoland/rev/947da40a7eda
Only handle hashchange event for the current window. r=ato
https://hg.mozilla.org/mozilla-central/rev/7b2de127cc03
https://hg.mozilla.org/mozilla-central/rev/947da40a7eda
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
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

Created:
Updated:
Size: