Closed
Bug 1118268
Opened 9 years ago
Closed 8 years ago
Intermittent testPrivateBrowsing | GeckoEventExpecter - blockForEvent timeout: Tab:Added
Categories
(Firefox for Android Graveyard :: General, defect)
Tracking
(firefox48 fixed)
RESOLVED
FIXED
Firefox 48
Tracking | Status | |
---|---|---|
firefox48 | --- | fixed |
People
(Reporter: RyanVM, Assigned: gbrown)
References
Details
(Keywords: intermittent-failure)
Attachments
(6 files)
81.18 KB,
text/plain
|
Details | |
32.90 KB,
image/jpeg
|
Details | |
MozReview Request: Bug 1118268 - Wait for animations to finish when selecting menu items. r=margaret
58 bytes,
text/x-review-board-request
|
Details | |
226.34 KB,
image/png
|
Details | |
81.63 KB,
image/png
|
Details | |
1.92 KB,
patch
|
Margaret
:
review+
|
Details | Diff | Splinter Review |
See the attached log.
Reporter | ||
Comment 1•9 years ago
|
||
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Assignee | ||
Comment 20•9 years ago
|
||
The test selects "New Private Tab" from the menu and then waits for Tab:Added, but the recent screenshots here show that the menu is still displayed...a timing issue when making the menu selection? Maybe that item is not yet clickable?? mcomella -- Any interest? Or can you find an owner for this bug?
Assignee | ||
Updated•9 years ago
|
Flags: needinfo?(michael.l.comella)
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Assignee | ||
Comment 40•9 years ago
|
||
No failures in 3 weeks - maybe no need for follow-up?
Flags: needinfo?(michael.l.comella)
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 50•9 years ago
|
||
All recent failures have screenshots showing the menu (with New Private Tab enabled) displayed when the Tab:Added timeout occurs (as though the menu selection is not working).
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 52•9 years ago
|
||
2:39:56 INFO - TEST-START | testPrivateBrowsing 22:39:56 INFO - TEST-PASS | testPrivateBrowsing | Robocop tests need the test device screen to be powered on. - 22:39:56 INFO - TEST-PASS | testPrivateBrowsing | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready 22:39:56 INFO - EventExpecter: no longer listening for Gecko:Ready 22:39:56 INFO - TEST-PASS | testPrivateBrowsing | waiting for urlbar text to gain focus - urlbar text gained focus 22:39:56 INFO - TEST-PASS | testPrivateBrowsing | URL typed properly - about:blank should equal about:blank 22:39:56 INFO - TEST-PASS | testPrivateBrowsing | Given message occurred for registered event: {"errorType":"","bgColor":"transparent","type":"DOMContentLoaded","tabID":0} - DOMContentLoaded should equal DOMContentLoaded 22:39:56 INFO - EventExpecter: no longer listening for DOMContentLoaded 22:39:56 INFO - Dumping ALL the threads! 22:39:56 INFO - Thread[Instr: org.mozilla.gecko.FennecInstrumentationTestRunner,5,main] 22:39:56 INFO - dalvik.system.VMStack.getThreadStackTrace(Native Method) 22:39:56 INFO - java.lang.Thread.getStackTrace(Thread.java:579) 22:39:56 INFO - java.lang.Thread.getAllStackTraces(Thread.java:521) 22:39:56 INFO - org.mozilla.gecko.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:317) 22:39:56 INFO - org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:95) 22:39:56 INFO - org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:80) 22:39:56 INFO - org.mozilla.gecko.tests.PixelTest.addTab(PixelTest.java:63) 22:39:56 INFO - org.mozilla.gecko.tests.testPrivateBrowsing.addTab(testPrivateBrowsing.java:19) 22:39:56 INFO - org.mozilla.gecko.tests.testPrivateBrowsing.testPrivateBrowsing(testPrivateBrowsing.java:30) 22:39:56 INFO - java.lang.reflect.Method.invokeNative(Native Method) 22:39:56 INFO - java.lang.reflect.Method.invoke(Method.java:525) 22:39:56 INFO - android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214) 22:39:56 INFO - android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 54•9 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #50) > All recent failures have screenshots showing the menu (with New Private Tab > enabled) displayed when the Tab:Added timeout occurs (as though the menu > selection is not working). I investigated and found that the MotionEvent generated by robotium to click on the "New Private Tab" menu item can be observed by adding an onInterceptTouchEvent() handler to GeckoMenu, even when the test fails and the robocop screenshot shows the menu it still displayed. However, in the failure cases, onClick is not triggered: It looks like the click gets to GeckoMenu but is discarded. I have not been able to observe any GeckoMenu state differences that might account for the failure. However, while comparing logcats, I noticed that failures were strongly correlated with log messages associated with Gecko:DelayedStartup, like: http://hg.mozilla.org/mozilla-central/annotate/9a8f2342fb31/mobile/android/base/BrowserApp.java#l1762. If the "New Private Tab" click is being processed by GeckoMenu around the time that Gecko:DelayedStartup is being processed, the click is often discarded. Waiting for delayed startup before starting the test appears to eliminate the failure: (base/no changes) https://treeherder.mozilla.org/#/jobs?repo=try&revision=e2c4d5620d41 (wait for delayed startup) https://treeherder.mozilla.org/#/jobs?repo=try&revision=766cdc3c4c8b I would like to see the root cause of the failure determined and addressed, but I cannot find the missing connection between Gecko:DelayedStartup and this apparent fault in GeckoMenu. It looks like neither GeckoMenu nor testPrivateBrowsing are strongly owned. margaret -- Can you suggest a way forward?
Flags: needinfo?(margaret.leibovic)
Comment 55•9 years ago
|
||
(In reply to Geoff Brown [:gbrown] from comment #54) > I would like to see the root cause of the failure determined and addressed, > but I cannot find the missing connection between Gecko:DelayedStartup and > this apparent fault in GeckoMenu. It looks like neither GeckoMenu nor > testPrivateBrowsing are strongly owned. margaret -- Can you suggest a way > forward? I know that mcomella has recently been looking at GeckoMenu code, so he may have some insights. Looking into this myself, I don't see any connection between Gecko:DelayedStartup and a problem with GeckoMenu. One thought I had is that some menu items are disabled until Gecko is up and running (e.g. Settings), so maybe something is happening where updating the menu is causing the clicks to fail, although that happens on "Gecko:Ready": http://hg.mozilla.org/mozilla-central/annotate/67a788db9f07/mobile/android/base/BrowserApp.java#l1796 Sorry I can't be more helpful :(
Flags: needinfo?(margaret.leibovic) → needinfo?(michael.l.comella)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
This could be related to bug 1217484 comment 8. The solution appears to be waiting for the animations to finish before clicking on the next thing.
See Also: → 1217484
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•8 years ago
|
tracking-fennec: --- → ?
Comment 64•8 years ago
|
||
Actually, I'll just try taking a look at this.
Assignee: nobody → margaret.leibovic
tracking-fennec: ? → ---
Comment hidden (Intermittent Failures Robot) |
See comment 60, if you haven't already.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee: margaret.leibovic → michael.l.comella
Flags: needinfo?(michael.l.comella)
testPrivateBrowsing selects menu items to open a new tab and I suspect the failures occur because we don't wait for the animations to finish before attempting to click again, like in bug 1217484 comment 8. Review commit: https://reviewboard.mozilla.org/r/32825/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/32825/
Attachment #8713795 -
Flags: review?(margaret.leibovic)
Comment 74•8 years ago
|
||
(In reply to Michael Comella (:mcomella) from comment #73) > Created attachment 8713795 [details] > MozReview Request: Bug 1118268 - Wait for animations to finish when > selecting menu items. r=margaret > > testPrivateBrowsing selects menu items to open a new tab and I suspect the > failures occur because we don't wait for the animations to finish before > attempting to click again, like in bug 1217484 comment 8. Wait -- are we not disabling animations on our test devices? This is explicitly recommended at http://developer.android.com/training/testing/ui-testing/espresso-testing.html. gbrown: can you confirm or deny and file to get this done ASAP?
Flags: needinfo?(gbrown)
Assignee | ||
Comment 75•8 years ago
|
||
Animations are disabled on the 4.3 emulator.
Flags: needinfo?(gbrown)
Assignee | ||
Comment 76•8 years ago
|
||
On 2.3, I believe I was unable to find animation settings. (There are no Developer Options.)
(In reply to Geoff Brown [:gbrown] from comment #76) > On 2.3, I believe I was unable to find animation settings. (There are no > Developer Options.) It's in Settings -> Applications -> Development
Flags: needinfo?(gbrown)
Assignee | ||
Comment 78•8 years ago
|
||
Thanks, but there's no animation-related settings there. Just "USB Debugging", "Stay awake", and "Allow mock locations".
Flags: needinfo?(gbrown)
I'm not sure why my try push didn't run 4.3 tests but it passed ~10x on 2.3 – I'd say we should try landing it!
Assignee | ||
Comment 80•8 years ago
|
||
Maybe s/android-api-11/android-api-15/ ?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
(In reply to Geoff Brown [:gbrown] from comment #80) > Maybe s/android-api-11/android-api-15/ ? Pushed to try via reviewboard w/ api-15.
I got two failures with my change, the stack is: 11:43:57 INFO - org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:80) 11:43:57 INFO - org.mozilla.gecko.tests.PixelTest.addTab(PixelTest.java:64) 11:43:57 INFO - org.mozilla.gecko.tests.testPrivateBrowsing.addTab(testPrivateBrowsing.java:19) Which is the DOMContentLoaded event expecter. There's no screenshot so it's hard to say which state we're getting stuck in (e.g. opening the menu, clicking the new tab button, or waiting for content to load). Geoff, do you know why there is sometimes a screenshot and sometimes not?
Flags: needinfo?(gbrown)
Assignee | ||
Comment 85•8 years ago
|
||
No, I don't know. The screenshot is requested at http://hg.mozilla.org/mozilla-central/annotate/d07dbd40dcd2/mobile/android/tests/browser/robocop/src/org/mozilla/gecko/tests/BaseRobocopTest.java#l192 -- which should have been hit in this case.
Flags: needinfo?(gbrown)
Without a screenshot (btw, filed bug 1244906 to find out why they're missing), I'm going to shoot this one back to Margaret – I have other things to focus on.
Assignee: michael.l.comella → margaret.leibovic
Assignee | ||
Comment 87•8 years ago
|
||
https://treeherder.mozilla.org/#/jobs?repo=try&revision=bfdc25bcc6ad reproduces this failure with mcomella's patch (not listed on the treeherder push, but it *is* there) and screenshots. I used an experimental technique to get a screenshot of the host when the test has not produced any output for 120 seconds. Screenshots are uploaded as artifacts named 'mozilla-test-fail-screenshot...'. For example: http://mozilla-releng-blobs.s3.amazonaws.com/blobs/try/sha512/3e27f60d8865c9b3c8da50e31749593d527103b53327ffbe3f002ea2eb2ef18a7315d0f317b5b95979aae6bd3f2b854a75132790fe4affe00394f149d0bf34e4 shows about:blank in the url bar and the menu open.
Attachment #8713795 -
Flags: review?(margaret.leibovic)
So we have an issue finding/clicking on the menu item. Looking at UITest's AppMenuComponent.findAppMenuItemView (which I also think only works some of the time), we seem to have a more robust mechanism where we search through all the views for the specific view types our menu items can be and click those – maybe we should use AppMenuComponent directly or (less preferably) steal that algorithm for BaseTest. We could also add logging to BaseTest.selectMenuItem.
Assignee | ||
Comment 89•8 years ago
|
||
I don't think the problem is in UITest: recall comment 54.
Assignee | ||
Comment 90•8 years ago
|
||
s/UITest/BaseTest/any of the test code/
Oops, I missed comment 54 (best ignore my work then :\ – I was just trying to fix the failure). Jim, can you take a look at comment 54 and let us know if you have any ideas what might be up?
Flags: needinfo?(nchen)
Comment 92•8 years ago
|
||
Sorry I'm not familiar with GeckoMenu or how it relates to Gecko:DelayedStartup.
Flags: needinfo?(nchen)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 99•8 years ago
|
||
A speculative improvement: If the cause of this failure is that GeckoMenu is not receiving the click sent by robotium, maybe there is a timing issue in robocop's menu item selection. Is robocop clicking on the item before the onClick handler is ready? Before the item is enabled? This has 3 changes in selectMenuItem(): - open the menu with view clicks rather than simulating the Menu key - remove old, unused More/Tools support (Tools items can still be accessed with selectMenuItemByPath) - waitForEnabledText instead of waitForText Encouraging try results: https://treeherder.mozilla.org/#/jobs?repo=try&revision=94c4b14c7143
Attachment #8734742 -
Flags: review?(margaret.leibovic)
Comment hidden (Intermittent Failures Robot) |
Comment 101•8 years ago
|
||
Comment on attachment 8734742 [details] [diff] [review] improve menu item selection Review of attachment 8734742 [details] [diff] [review]: ----------------------------------------------------------------- Nice, this looks reasonable to me.
Attachment #8734742 -
Flags: review?(margaret.leibovic) → review+
Updated•8 years ago
|
Assignee: margaret.leibovic → gbrown
Comment 103•8 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/926f349435b2
Status: NEW → RESOLVED
Closed: 8 years ago
status-firefox48:
--- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 48
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in
before you can comment on or make changes to this bug.
Description
•