Closed Bug 1369923 Opened 7 years ago Closed 6 years ago

Intermittent test_navigation.py TestNavigate.test_type_to_non_remote_tab | TimeoutException: Timed out after 300.1 seconds with message: 'about:support' hasn't been loaded

Categories

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

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

Tracking

(firefox56 disabled, firefox57 disabled, firefox58 disabled, firefox64 disabled, firefox65 disabled, firefox66 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla66
Tracking Flags:
Tracking Status
firefox56 --- disabled
firefox57 --- disabled
firefox58 --- disabled
firefox64 --- disabled
firefox65 --- disabled
firefox66 --- fixed

People

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

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

Disabling test
1.03 KB, patch
Details | Diff | Splinter Review
Bug 1369923 - [marionette] Re-enable test TestNavigate.test_type_to_non_remote_tab. r?ato
47 bytes, text/x-phabricator-request
Details | Review 
[task 2017-06-02T16:18:38.904625Z] 16:18:38     INFO - TEST-UNEXPECTED-ERROR | test_navigation.py TestNavigate.test_type_to_non_remote_tab | TimeoutException: Timed out after 300.1 seconds with message: 'about:support' hasn't been loaded
[task 2017-06-02T16:18:38.906962Z] 16:18:38     INFO - Traceback (most recent call last):
[task 2017-06-02T16:18:38.908212Z] 16:18:38     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 166, in run
[task 2017-06-02T16:18:38.910167Z] 16:18:38     INFO -     testMethod()
[task 2017-06-02T16:18:38.911980Z] 16:18:38     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_harness/marionette_test/decorators.py", line 150, in skip_wrapper
[task 2017-06-02T16:18:38.913256Z] 16:18:38     INFO -     return test_item(self, *args, **kwargs)
[task 2017-06-02T16:18:38.914555Z] 16:18:38     INFO -   File "/home/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py", line 233, in test_type_to_non_remote_tab
[task 2017-06-02T16:18:38.916469Z] 16:18:38     INFO -     message="'about:support' hasn't been loaded")
[task 2017-06-02T16:18:38.918231Z] 16:18:38     INFO -   File "/home/worker/workspace/build/venv/local/lib/python2.7/site-packages/marionette_driver/wait.py", line 150, in until
[task 2017-06-02T16:18:38.919437Z] 16:18:38     INFO -     cause=last_exc)

From gecko.log:

1496420018557	Marionette	TRACE	1026 -> [0,27,"findElement",{"using":"id","value":"urlbar"}]
1496420018558	Marionette	TRACE	1026 <- [1,27,null,{"value":{"element-6066-11e4-a52e-4f735466cecf":"f6022dce-36ce-47ea-a832-6c41327b933a","ELEMENT":"f6022dce-36ce-47ea-a832-6c41327b933a"}}]
1496420018561	Marionette	TRACE	1026 -> [0,28,"sendKeysToElement",{"text":"a","id":"f6022dce-36ce-47ea-a832-6c41327b933a"}]
1496420018576	Marionette	TRACE	1026 <- [1,28,null,{}]
1496420018580	Marionette	TRACE	1026 -> [0,29,"sendKeysToElement",{"text":"x","id":"f6022dce-36ce-47ea-a832-6c41327b933a"}]
1496420018587	Marionette	TRACE	1026 <- [1,29,null,{}]
1496420018589	Marionette	TRACE	1026 -> [0,30,"sendKeysToElement",{"text":"about:support","id":"f6022dce-36ce-47ea-a832-6c41327b933a"}]
1496420018622	Marionette	TRACE	1026 <- [1,30,null,{}]

It's not clear to me if "" is the RETURN key or not. Andreas, is there an easy way to figure that out?
Flags: needinfo?(ato)
It _should_ be the `Keys.ENTER`. Since this is using PUA unicode, my guess is mozlog can't print these characters out properly.
Flags: needinfo?(ato)
The return key is the U+E006 PUA (private use area) Unicode character.

> >>> print u'\ue006'
> 
FWIW you could find this out from the WebDriver specification’s ‘normalised key value’ table and the Python REPL: https://w3c.github.io/webdriver/webdriver-spec.html#keyboard-actions
So I have to do the following locally to get it working. But then I still do not get `` but ``.

> print u'\ue006'.encode("utf-8")
> 

Maybe we should wait for other failures like this before continuing with any investigation.
Well it’s easy enough to find this out by looking at the source code.  test_navigation.py:225 ff. reads:

>         with self.marionette.using_context("chrome"):
>             urlbar = self.marionette.find_element(By.ID, "urlbar")
>             urlbar.send_keys(self.mod_key + "a")
>             urlbar.send_keys(self.mod_key + "x")
>             urlbar.send_keys("about:support" + Keys.ENTER)

And Keys.ENTER in testing/marionette/client/marionette_driver/keys.py:26 is:

> ENTER = u'\ue007'

And in the Python REPL:

>>> print u"\uE007"
Above you said \uE006, and now it is \uE007. Looking at the spec we have:

> \uE006 "Return"
> \uE007	 "Enter"

What is the difference here? Might Firefox handle it differently?
(In reply to Henrik Skupin (:whimboo) from comment #7)
> Above you said \uE006, and now it is \uE007. Looking at the spec we have:
> 
> > \uE006 "Return"
> > \uE007	 "Enter"
> 
> What is the difference here? Might Firefox handle it differently?

You will find the answer to your question in the source at https://searchfox.org/mozilla-central/rev/d441cb24482c2e5448accaf07379445059937080/testing/marionette/action.js#63-64:

> const NORMALIZED_KEY_LOOKUP = {

…

>   "\uE006": "Enter",
>   "\uE007": "Enter",

In Marionette we treat them both the same, so they are not handled differently
in Firefox, but I suppose there are platforms and browsers where differentiating
them might make sense.
I see. Ok, so lets wait for more failure if those appear.
(In reply to Henrik Skupin (:whimboo) from comment #1)
> 1496420018589	Marionette	TRACE	1026 ->
> [0,30,"sendKeysToElement",{"text":"about:support","id":"f6022dce-36ce-
> 47ea-a832-6c41327b933a"}]
> 1496420018622	Marionette	TRACE	1026 <- [1,30,null,{}]
> 
> It's not clear to me if "" is the RETURN key or not. Andreas, is there an
> easy way to figure that out?

So here a comparison to a passing test job:

1497727606402	Marionette	TRACE	1032 -> [0,28,"sendKeysToElement",{"text":"a","id":"0695bdac-255b-4c8a-bd0a-a3c9cf910f3a"}]
1497727606413	Marionette	TRACE	1032 <- [1,28,null,{}]
1497727606422	Marionette	TRACE	1032 -> [0,29,"sendKeysToElement",{"text":"x","id":"0695bdac-255b-4c8a-bd0a-a3c9cf910f3a"}]
1497727606430	Marionette	TRACE	1032 <- [1,29,null,{}]
1497727606435	Marionette	TRACE	1032 -> [0,30,"sendKeysToElement",{"text":"about:support","id":"0695bdac-255b-4c8a-bd0a-a3c9cf910f3a"}]
1497727606462	Marionette	TRACE	1032 <- [1,30,null,{}]
1497727606481	Marionette	TRACE	1032 -> [0,31,"setContext",{"value":"content"}]
1497727606482	Marionette	TRACE	1032 <- [1,31,null,{}]
1497727606486	Marionette	TRACE	1032 -> [0,32,"getTimeouts",{}]
1497727606486	Marionette	TRACE	1032 <- [1,32,null,{"implicit":0,"pageLoad":300000,"script":30000}]
1497727606487	Marionette	TRACE	1032 -> [0,33,"getCurrentUrl",{}]
1497727606487	Marionette	TRACE	1032 <- [1,33,null,{"value":"about:robots"}]
1497727606586	Marionette	TRACE	1032 -> [0,34,"getCurrentUrl",{}]
1497727606586	Marionette	TRACE	1032 <- [1,34,null,{"value":"about:robots"}]
1497727606702	Marionette	TRACE	1032 -> [0,35,"getCurrentUrl",{}]
1497727606703	Marionette	TRACE	1032 <- [1,35,null,{"value":"about:support"}]

Means the Return key is equally encoded and works fine. I wonder if that has something to do with my changes on bug 1368101.

All the failures on Linux are happening for headless Marionette jobs. CC'ing Brendan.
:automatedtester, this is failing at a very high failure rate, can you get someone to look into fixing this in the next week?
Flags: needinfo?(dburns)
Whiteboard: [stockwell needswork]
Looking at this, we don't see be triggering the page load code.
Flags: needinfo?(dburns)
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled][checkin-needed]
Whiteboard: [stockwell disabled][checkin-needed] → [stockwell disabled]
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE

This test is still disabled, which is the reason why it didn't fail anymore. We should check if it can be unskipped.

Status: RESOLVED → REOPENED
status-firefox64: --- → disabled
status-firefox65: --- → disabled
status-firefox66: --- → disabled
Keywords: leave-open
Resolution: INCOMPLETE → ---
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9da0a9e7fef3
[marionette] Re-enable test TestNavigate.test_type_to_non_remote_tab. r=jgraham
Assignee: nobody → hskupin
Status: REOPENED → RESOLVED
Closed: 7 years ago → 6 years ago
status-firefox66: disabled → fixed
Keywords: leave-open, test-disabled
Resolution: --- → FIXED
Whiteboard: [stockwell disabled]
Priority: -- → P2
Target Milestone: --- → mozilla66
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

Creator:
Created:
Updated:
Size: