Intermittent TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed

RESOLVED WORKSFORME

Status

()

Firefox for Android
General
RESOLVED WORKSFORME
4 years ago
3 years ago

People

(Reporter: Tomcat, Unassigned)

Tracking

({intermittent-failure})

Trunk
x86
Android
intermittent-failure
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

(URL)

Attachments

(2 attachments, 1 obsolete attachment)

(Reporter)

Description

4 years ago
Android 4.0 Panda mozilla-inbound opt test robocop-1 on 2013-10-09 23:22:44 PDT for push aa11ee736eff

slave: panda-0346

https://tbpl.mozilla.org/php/getParsedLog.php?id=28915439&tree=Mozilla-Inbound

8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed

followed by other errors like

junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
9 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
10-09 23:36:56.375 I/Robocop ( 2283): 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
10-09 23:36:56.421 I/Robocop ( 2283): junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
10-09 23:36:56.445 I/Robocop ( 2283): 9 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
10-09 23:36:57.617 I/TestRunner( 2283): junit.framework.AssertionFailedError: 9 INFO TEST-UNEXPECTED-FAIL | testBookmark | Exception caught - junit.framework.AssertionFailedError: 8 INFO TEST-UNEXPECTED-FAIL | testBookmark | Checking if http://mochi.test:8888/tests/robocop/robocop_blank_01.html is displayed in the Bookmarks Tab - The bookmark is displayed
Return code: 1
Created attachment 815260 [details]
screenshot.jpg

Screenshot shows something we've seen before ... the child(0) is missing / wrong ... the target bookmark item appears to be in the list, but the horizontal divider above it indicates that it's the child(1) so the test didnt see it in the right place ...

I'm starting to thing this is related to bug 920507 that I'm working on ...

Good news: I understand bug 920507 and how to fix it (waiting on review/approval) ... Bad news ... I don't see the strong connection here ... other than there is a problem with about:home fragmentadapter having what appears to be an invalid item ...

is this the same getCount() value issue?
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Created attachment 821288 [details]
good.jpg

cc: margaret for feedback ...

I pushed to TRY a debug build, with a custom built ROBOTIUM, for additional details where I thought they might be needed to track down our annoying robocop random oranges.

I triggered several tests and quickly got a random orange in testBookmark.java.in:
https://tbpl.mozilla.org/?tree=Try&rev=1e4df81bdf54

I think I see a problem affecting consumers of AboutHomeTest.getDisplayedBookmark() ...

The orange failure of testBookmark.java.in shows interesting information. Scan the full log for the DEBUG string:
|testBookmark | XYZZY - AboutHomeTest.java.in - getDisplayedBookmark()|
>>> see attached normal / expected SCREENSHOT from this point I generated locally

Comparing two tests (the preceeding green log and this orange log):

After the routine navigates to the proper about:home tab |findListViewWithTag("bookmarks");| ... it starts to traverse the UI view looking for the item that should have been previously bookmarked and be visible in the list.

Both tests start with the same bookmark adapter listCount (5). (Ignoring for now the first item(0) that seems to be consistently empty and perhaps explains the immediate listitem seperator at the top of the page that is observable on my N7 but not on my GS3) ... 

The second item (1) is the target TwoLinePageRow we're testing for and hope to return from the loop, but in the orange case we get a null value for |View bookmarkView = bookmarksTabList.getChildAt(i);| ???

Is it possible the list count is correct, but our test has raced ahead of the UI composition ?
Attachment #815260 - Attachment is obsolete: true
Attachment #821288 - Flags: feedback?(margaret.leibovic)
Comment hidden (Treeherder Robot)
Attachment #821288 - Flags: feedback?(margaret.leibovic)
Created attachment 821554 [details] [diff] [review]
bug925264 (v)

This patch allows the testBookmark.java.in to gracefully handle slow UI response in two different situations, both at the root cause of this particular random orange. In testing, roughly 1 failure out of 100 tests was observed, both locally and on TRY.

Pushing the fix to TRY and testing provides one example that /did not/ random orange but would have:
https://tbpl.mozilla.org/php/getParsedLog.php?id=29587176&tree=Try&full=1

Search for the tag |sleeps|
Assignee: nobody → markcapella
Status: NEW → ASSIGNED
Attachment #821554 - Flags: review?(margaret.leibovic)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Could we use waitForCondition instead of these custom sleep loops?
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment on attachment 821554 [details] [diff] [review]
bug925264 (v)

Holding this ... waiting on a dep
Attachment #821554 - Flags: review?(margaret.leibovic)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Attachment #821554 - Flags: review?(margaret.leibovic)
The log for the error in comment #23 added earlier today is a weird situation in the same routine that this patch won't fix where robotium is throwing an exception that I'm tracking in bug915449.
Comment hidden (Treeherder Robot)

Comment 27

4 years ago
Comment on attachment 821554 [details] [diff] [review]
bug925264 (v)

Review of attachment 821554 [details] [diff] [review]:
-----------------------------------------------------------------

I'm redirecting this to gbrown, since he's more in the loop with robocop changes. However, I do have some feedback about these new helper methods you made. Also, like gbrown mentioned in an earlier comment, is there any existing functionality we could use here, rather than implementing these new wait methods?

::: mobile/android/base/tests/AboutHomeTest.java.in
@@ +111,5 @@
>                  // I am unable to click the view taken with getView for some reason so getting the child at i
>                  bookmarksTabList.smoothScrollToPosition(i);
> +
> +                // Wait for child view
> +                View bookmarkView = (View) waitForObjectAtIndex(new ObjectAtIndexTest() {

Why do these new helper methods deal with Objects and not just with Views? They seem unnecessarily generic, and it would be nice to avoid the need for casting everything.
Attachment #821554 - Flags: review?(margaret.leibovic) → review?(gbrown)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Thanks margaret. The short status is there's a bug that can be fixed by adding a wait loop. I actually trapped and fixed two bugs, one TBPL I attached as evidence, the other I could talk about.

example of the orange (3) in a TRY run:
   https://tbpl.mozilla.org/?tree=Try&rev=1e4df81bdf54
example of the fix in a green TRY run.
   https://tbpl.mozilla.org/php/getParsedLog.php?id=29587176&tree=Try&full=1

This is additionally cool, as this tightens routines in AboutHomeTest that iirc others call into and at least one didn't check results.

I created the helpers thinking that if our tests are running faster than the UI composition, maybe we could throttle behind the process and/or I should learn more about it.

The helpers were a way to check more than just a Y/N condition, but allow us to test for and return value or null (it seemed like an extra layer of granularity). There's often easier ways to accomplish things than I usually come up with first, so if there is and we fix this bug, \o/! Us!

The current thing that attracts me is the |Exception caught during test!| messages I'm also encountering in this bug, as well as a host of our other tests, notably

bug 915449 - https://bugzilla.mozilla.org/show_bug.cgi?id=915449
   Intermittent testNewTab, testShareLink, testSearchSuggestions, testBookmark
      Exception caught during test!
         junit.framework.AssertionFailedError: EditText is not found!

I'm tracking that on bug 915449 testNewTab, as I can easily reproduce in one out of ~70 local runs. (The test iself is small / tightly defined, and runs fast). I can't explain it but looking into robotium it seems like the bug happens when we're at a point well into testing / processing and have been navigating through the UI screens, when we call robotium to find a desired view, and it goes to it's list of where those things exist, but it finds a null pointer.

After 10 seconds of looking internally at a black screen it throws up it's hands and gives us up. My only guess atm is that this ties into why some portions of the screen don't present during screeshot capture (the gecko portion)?
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Mark Capella [:capella] from comment #36)
> The helpers were a way to check more than just a Y/N condition, but allow us
> to test for and return value or null (it seemed like an extra layer of
> granularity). There's often easier ways to accomplish things than I usually
> come up with first, so if there is and we fix this bug, \o/! Us!

I would really like to leverage waitForCondition if we can. If it is only a matter of getting objects/views in return and/or passing parameters, I think you can do that by subclassing Condition. Then your SubCondition can accept parameters on creation, and provide something like SubCondition.getFoundObject() to return something after waitForCondition is complete.

> After 10 seconds of looking internally at a black screen it throws up it's
> hands and gives us up. My only guess atm is that this ties into why some
> portions of the screen don't present during screeshot capture (the gecko
> portion)?

Solo.takeScreenshot never gives us captures of our content view, afaik; I think that is an expected limitation of Solo.takeScreenshot -- it just doesn't work with that type of view. Sorry, I cannot find a reference for that, but I remember reading it somewhere....
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment on attachment 821554 [details] [diff] [review]
bug925264 (v)

Review of attachment 821554 [details] [diff] [review]:
-----------------------------------------------------------------

Clearing the review for now, while we discuss Comment 41.
Attachment #821554 - Flags: review?(gbrown)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Status: ASSIGNED → NEW
Assignee: markcapella → nobody
Closing bugs where TBPLbot has previously commented, but have now not been modified for >3 months & do not contain the whiteboard strings for disabled/annotated tests or use the keyword leave-open. Filter on: mass-intermittent-bug-closure-2014-07
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.