Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py TestScreenOrientation.test_set_orientation_portrait_secondary | TimeoutException: Timed out after 5.1 seconds
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Tracking
(firefox68 fixed, firefox69 disabled)
People
(Reporter: intermittent-bug-filer, Unassigned)
References
Details
(5 keywords, Whiteboard: [stockwell unknown])
Attachments
(1 file)
#[markdown(off)]
Filed by: ncsoregi [at] mozilla.com
https://treeherder.mozilla.org/logviewer.html#?job_id=232200024&repo=autoland
[task 2019-03-06T17:17:33.256Z] 17:17:33 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py TestScreenOrientation.test_set_orientation_portrait_secondary
[task 2019-03-06T17:17:38.735Z] 17:17:38 WARNING - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py TestScreenOrientation.test_set_orientation_portrait_secondary | TimeoutException: Timed out after 5.1 seconds
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - Traceback (most recent call last):
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - testMethod()
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 33, in wrapper
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - return func(self, *args, **kwargs)
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/decorators.py", line 114, in skip_wrapper
[task 2019-03-06T17:17:38.735Z] 17:17:38 INFO - return test_item(self, *args, **kwargs)
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py", line 44, in test_set_orientation
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - self.wait_for_orientation(orientation)
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py", line 35, in wait_for_orientation
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - lambda _: self.marionette.orientation == orientation)
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/wait.py", line 154, in until
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - cause=last_exc)
[task 2019-03-06T17:17:38.736Z] 17:17:38 INFO - TEST-INFO took 5479ms
![]() |
||
Comment 1•6 years ago
|
||
This started failing intermittently when we moved android marionette to the 7.0 x86_64 emulator.
Comment 2•6 years ago
|
||
Looks like the new orientation isn't accepted and it returns again to portrait-primary
:
03-07 04:52:57.032 2642 2660 I Gecko : 1551934377032 Marionette DEBUG 673 -> [0,5,"Marionette:SetScreenOrientation",{"orientation":"portrait-secondary"}]
03-07 04:52:57.034 2642 2660 D GeckoScreenOrientation: locking to PORTRAIT_SECONDARY
03-07 04:52:57.189 2642 2660 D GeckoScreenOrientation: updating to new orientation PORTRAIT_SECONDARY
03-07 04:52:57.190 2642 2642 D GeckoScreenOrientation: updating to new orientation PORTRAIT_PRIMARY
03-07 04:52:57.199 2642 2660 I Gecko : 1551934377199 Marionette DEBUG 673 <- [1,5,null,{"value":null}]
03-07 04:52:57.214 2642 2660 I Gecko : 1551934377214 Marionette DEBUG 673 -> [0,6,"Marionette:GetScreenOrientation",{}]
03-07 04:52:57.220 1535 1578 I InputReader: Reconfiguring input devices. changes=0x00000004
03-07 04:52:57.220 1535 1578 I InputReader: Device reconfigured: id=0, name='qwerty2', size 800x1280, orientation 2, mode 1, display id 0
03-07 04:52:57.231 2642 2660 I Gecko : 1551934377231 Marionette DEBUG 673 <- [1,6,null,{"value":"portrait-primary"}]
Jan, do you have an idea?
Comment 3•6 years ago
|
||
Without the debug logging that gbrown added temporarily for one of those try runs it's hard to say.
Comment 4•6 years ago
|
||
Hm not sure what that was. Geoff, could you please do the same? Looks like that we might hit this issue on try.
Updated•6 years ago
|
![]() |
||
Comment 5•6 years ago
|
||
I think I have the logging here and am trying to reproduce this failure:
![]() |
||
Comment 6•6 years ago
|
||
Logging with a failure:
https://treeherder.mozilla.org/logviewer.html#?job_id=232702759&repo=try
Comment hidden (Intermittent Failures Robot) |
Comment 8•6 years ago
|
||
There is another request to switch back to portrait-primary
, which is not initiated by Marionette:
03-08 16:44:57.510 2422 2444 I Gecko : 1552063497510 Marionette DEBUG 673 -> [0,5,"Marionette:SetScreenOrientation",{"orientation":"portrait-secondary"}]
03-08 16:44:57.510 2422 2444 D GeckoScreenOrientation: locking to PORTRAIT_SECONDARY
03-08 16:44:57.600 1315 1357 I InputReader: Reconfiguring input devices. changes=0x00000004
03-08 16:44:57.600 1315 1357 I InputReader: Device reconfigured: id=0, name='qwerty2', size 800x1280, orientation 2, mode 1, display id 0
03-08 16:44:57.600 2422 2444 D GeckoScreenOrientation: request for new orientation PORTRAIT_SECONDARY
03-08 16:44:57.600 2422 2444 D GeckoScreenOrientation: updating to new orientation PORTRAIT_SECONDARY
03-08 16:44:57.610 2422 2444 W System.err: java.lang.Exception
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.GeckoScreenOrientation.update(GeckoScreenOrientation.java:167)
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.GeckoScreenOrientation.lock(GeckoScreenOrientation.java:254)
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.GeckoScreenOrientation.lock(GeckoScreenOrientation.java:236)
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.GeckoAppShell.lockScreenOrientation(GeckoAppShell.java:1697)
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method)
03-08 16:44:57.610 2422 2444 W System.err: at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:474)
03-08 16:44:57.610 2422 2444 D GeckoScreenOrientation: update complete for PORTRAIT_SECONDARY
03-08 16:44:57.610 2422 2422 D GeckoScreenOrientation: request for new orientation PORTRAIT_PRIMARY
03-08 16:44:57.610 2422 2422 D GeckoScreenOrientation: updating to new orientation PORTRAIT_PRIMARY
03-08 16:44:57.610 2422 2422 W System.err: java.lang.Exception
03-08 16:44:57.610 2422 2422 W System.err: at org.mozilla.gecko.GeckoScreenOrientation.update(GeckoScreenOrientation.java:167)
03-08 16:44:57.610 2422 2422 W System.err: at org.mozilla.gecko.GeckoScreenOrientation.update(GeckoScreenOrientation.java:143)
03-08 16:44:57.610 2422 2422 W System.err: at org.mozilla.geckoview.GeckoRuntime.orientationChanged(GeckoRuntime.java:447)
03-08 16:44:57.610 2422 2422 W System.err: at org.mozilla.geckoview.GeckoView.onConfigurationChanged(GeckoView.java:468)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.View.dispatchConfigurationChanged(View.java:10418)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1311)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewGroup.dispatchConfigurationChanged(ViewGroup.java:1315)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewRootImpl.updateConfiguration(ViewRootImpl.java:3337)
03-08 16:44:57.610 2422 2422 W System.err: at android.view.ViewRootImpl$ViewRootHandler.handleMessage(ViewRootImpl.java:3494)
03-08 16:44:57.610 2422 2422 W System.err: at android.os.Handler.dispatchMessage(Handler.java:102)
03-08 16:44:57.610 2422 2422 W System.err: at android.os.Looper.loop(Looper.java:154)
03-08 16:44:57.610 2422 2422 W System.err: at android.app.ActivityThread.main(ActivityThread.java:6077)
03-08 16:44:57.610 2422 2422 W System.err: at java.lang.reflect.Method.invoke(Native Method)
03-08 16:44:57.610 2422 2422 W System.err: at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
03-08 16:44:57.610 2422 2422 W System.err: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
03-08 16:44:57.620 2422 2422 D GeckoScreenOrientation: update complete for PORTRAIT_PRIMARY
03-08 16:44:57.630 2422 2444 I Gecko : 1552063497630 Marionette DEBUG 673 <- [1,5,null,{"value":null}]
03-08 16:44:57.630 2422 2444 I Gecko : 1552063497630 Marionette DEBUG 673 -> [0,6,"Marionette:GetScreenOrientation",{}]
03-08 16:44:57.630 2422 2444 I Gecko : 1552063497630 Marionette DEBUG 673 <- [1,6,null,{"value":"portrait-primary"}]
Comment 9•6 years ago
•
|
||
Is that failure the result of bug 1527959?
Comment hidden (Intermittent Failures Robot) |
Comment 11•6 years ago
|
||
Yes, seems like it. Sorry for the lack of progress there, but I haven't had much time for actual coding recently.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 16•6 years ago
|
||
This bug has failed 44 times in the last 7 days. Occurs on android-em-7-0-x86_64 on opt and debug build types.
Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241204980&repo=autoland&lineNumber=2865
Comment hidden (Intermittent Failures Robot) |
Comment 18•6 years ago
|
||
(In reply to Dorel Luca [:dluca] from comment #16)
This bug has failed 44 times in the last 7 days. Occurs on android-em-7-0-x86_64 on opt and debug build types.
Where do you see 44 failures? Latest intermittent comment only states 17 failures.
Comment 19•6 years ago
|
||
Same as for the other bug where you asked me.
Check this link:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-04-11&endday=2019-04-18&tree=all&bug=1533084
Comment 20•6 years ago
|
||
Geoff, I assume that this bug might also be affected by the slowdown of machines via packet.net (bug 1545308). The failure rate increased a lot over the last two weeks. Could you please verify?
![]() |
||
Comment 21•6 years ago
|
||
Based on performance logs from the last few days, this bug is not related to bug 1545308.
Comment hidden (Intermittent Failures Robot) |
Comment 23•6 years ago
|
||
There are 32 total failures in the last 7 day on android-em-7-0-x86_64: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-04-24&endday=2019-05-01&tree=trunk&bug=1533084
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=243832333&repo=mozilla-inbound&lineNumber=2869
[task 2019-05-01T05:33:41.890Z] 05:33:41 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py TestScreenOrientation.test_set_orientation_portrait_secondary
[task 2019-05-01T05:33:48.466Z] 05:33:48 WARNING - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py TestScreenOrientation.test_set_orientation_portrait_secondary | TimeoutException: Timed out after 5.0 seconds
[task 2019-05-01T05:33:48.466Z] 05:33:48 INFO - Traceback (most recent call last):
[task 2019-05-01T05:33:48.467Z] 05:33:48 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-05-01T05:33:48.467Z] 05:33:48 INFO - testMethod()
[task 2019-05-01T05:33:48.468Z] 05:33:48 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 33, in wrapper
[task 2019-05-01T05:33:48.468Z] 05:33:48 INFO - return func(self, *args, **kwargs)
[task 2019-05-01T05:33:48.469Z] 05:33:48 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/decorators.py", line 114, in skip_wrapper
[task 2019-05-01T05:33:48.469Z] 05:33:48 INFO - return test_item(self, *args, **kwargs)
[task 2019-05-01T05:33:48.469Z] 05:33:48 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py", line 44, in test_set_orientation
[task 2019-05-01T05:33:48.470Z] 05:33:48 INFO - self.wait_for_orientation(orientation)
[task 2019-05-01T05:33:48.470Z] 05:33:48 INFO - File "/builds/worker/workspace/build/tests/marionette/tests/testing/marionette/harness/marionette_harness/tests/unit/test_screen_orientation.py", line 35, in wait_for_orientation
[task 2019-05-01T05:33:48.471Z] 05:33:48 INFO - lambda _: self.marionette.orientation == orientation)
[task 2019-05-01T05:33:48.471Z] 05:33:48 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/marionette_driver/wait.py", line 154, in until
[task 2019-05-01T05:33:48.471Z] 05:33:48 INFO - cause=last_exc)
[task 2019-05-01T05:33:48.471Z] 05:33:48 INFO - TEST-INFO took 6585ms
David, could you please assign this to someone?
Comment hidden (Intermittent Failures Robot) |
Comment 25•6 years ago
|
||
There has been a significant drop in the intermittence rate with no changes on our end so think that it could be related to bug 1545308
Comment 26•6 years ago
|
||
Yes, I also assume so. Right now no more failures since 24h ago. Lets wait until Monday before closing this bug.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 31•6 years ago
|
||
(In reply to Jan Henning [:JanH] (away in June) from comment #11)
Yes, seems like it. Sorry for the lack of progress there, but I haven't had much time for actual coding recently.
Looks like Jan isn't around in June. Which means if the number of failures stays high, we might have to disable this test. Jan, when you returned maybe you could let us know when you think that you can work on bug 1527959 (or at all).
Comment 32•6 years ago
|
||
Sorry for not making much progress there - given the announcement of the Fennec EOL, I had hoped we might be able to muddle through until that time to avoid the complication of keeping the old implementation around, too, for API16 compatibility. "That time", i.e. the removal of the Fennec code from mozilla-central is only scheduled for 71, though, so still a little while away.
Comment 33•6 years ago
|
||
Thanks for the update! So I would suggest that we skip this test for Fennec only. We don't have the Marionette tests running for other browsers on Android, but once we do the test should be running immediately.
Comment 34•6 years ago
|
||
Turns out that with the Marionette specific parameterized
decorator we cannot simply skip a single platform. As such I have to completely comment out the following line:
Comment 35•6 years ago
|
||
Comment 36•6 years ago
|
||
Comment 37•6 years ago
|
||
Updated•6 years ago
|
Updated•6 years ago
|
Comment 38•6 years ago
|
||
bugherder |
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Comment 41•6 years ago
|
||
bugherder uplift |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Updated•2 years ago
|
Comment 44•2 years ago
|
||
Description
•