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

RESOLVED INCOMPLETE

Status

RESOLVED INCOMPLETE
a year ago
11 months ago

People

(Reporter: intermittent-bug-filer, Unassigned)

Tracking

({intermittent-failure, test-disabled})

Version 3
intermittent-failure, test-disabled
Points:
---

Firefox Tracking Flags

(firefox56 disabled, firefox57 disabled, firefox58 disabled)

Details

(Whiteboard: [stockwell disabled])

Attachments

(1 attachment)

[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.
2 failures in 814 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-beta: 1
* autoland: 1

Platform breakdown:
* linux64-nightly: 1
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-06-12&endday=2017-06-18&tree=all
(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.
8 failures in 892 pushes (0.009 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 4
* mozilla-inbound: 3
* mozilla-beta: 1

Platform breakdown:
* windows7-32-vm: 4
* linux64: 3
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-06-19&endday=2017-06-25&tree=all
1 failures in 718 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-06-26&endday=2017-07-02&tree=all
3 failures in 656 pushes (0.005 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 2
* mozilla-inbound: 1

Platform breakdown:
* windows7-32-vm: 2
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-03&endday=2017-07-09&tree=all
5 failures in 720 pushes (0.007 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-inbound: 3
* oak: 1
* autoland: 1

Platform breakdown:
* windows8-64: 3
* windows7-32: 1
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-10&endday=2017-07-16&tree=all
12 failures in 822 pushes (0.015 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 6
* mozilla-inbound: 4
* try: 1
* mozilla-beta: 1

Platform breakdown:
* windows7-32: 7
* windows8-64: 2
* linux64-devedition: 1
* linux64: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-17&endday=2017-07-23&tree=all
20 failures in 218 pushes (0.092 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* mozilla-inbound: 9
* autoland: 7
* mozilla-central: 2
* oak: 1
* mozilla-beta: 1

Platform breakdown:
* windows7-32: 17
* windows8-64: 1
* osx-10-10: 1
* linux64-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-26&endday=2017-07-26&tree=all
: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]
53 failures in 1008 pushes (0.053 failures/push) were associated with this bug in the last 7 days. 

This is the #48 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* mozilla-inbound: 27
* autoland: 20
* mozilla-central: 4
* oak: 1
* mozilla-beta: 1

Platform breakdown:
* windows7-32: 46
* windows10-64: 2
* osx-10-10: 2
* windows8-64: 1
* linux64-nightly: 1
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-24&endday=2017-07-30&tree=all
1 failures in 888 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-07-31&endday=2017-08-06&tree=all
1 failures in 901 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-release: 1

Platform breakdown:
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1369923&startday=2017-08-07&endday=2017-08-13&tree=all
status-firefox56: --- → disabled
status-firefox57: --- → disabled
status-firefox58: --- → disabled
Keywords: leave-open → test-disabled
https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Last Resolved: 11 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.