Closed Bug 813107 Opened 12 years ago Closed 7 years ago

Intermittent testThumbnails | Top site thumbnail updated for HTTP 200 - got -1 (or 0), expected -16711936

Categories

(Firefox for Android Graveyard :: Awesomescreen, defect, P3)

ARM
Android
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: emorley, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [test disabled][leave open])

Attachments

(1 file, 1 obsolete file)

Android Armv6 Tegra 250 profiling opt test robocop on 2012-11-18 22:32:51 PST for push 89df18f9b6da slave: tegra-165 https://tbpl.mozilla.org/php/getParsedLog.php?id=17163176&tree=Profiling { 1 INFO TEST-START | testThumbnails 2 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=changeColor should equal http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=changeColor 3 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=do404 should equal http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=do404 4 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - about:home should equal about:home 5 INFO TEST-UNEXPECTED-FAIL | testThumbnails | Top site thumbnail updated for HTTP 200 - got -1, expected -16711936 Exception caught during test! junit.framework.AssertionFailedError: 5 INFO TEST-UNEXPECTED-FAIL | testThumbnails | Top site thumbnail updated for HTTP 200 - got -1, expected -16711936 at junit.framework.Assert.fail(Assert.java:47) at org.mozilla.fennec.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:107) at org.mozilla.fennec.FennecMochitestAssert.ok(FennecMochitestAssert.java:136) at org.mozilla.fennec.FennecMochitestAssert.is(FennecMochitestAssert.java:142) at org.mozilla.fennec.tests.testThumbnails.testThumbnails(testThumbnails.java:57) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:521) at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204) at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194) at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186) at org.mozilla.fennec.tests.BaseTest.runTest(BaseTest.java:120) at junit.framework.TestCase.runBare(TestCase.java:127) at junit.framework.TestResult$1.protect(TestResult.java:106) at junit.framework.TestResult.runProtected(TestResult.java:124) at junit.framework.TestResult.run(TestResult.java:109) at junit.framework.TestCase.run(TestCase.java:118) at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169) at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154) at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:520) at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1447) 6 INFO TEST-UNEXPECTED-FAIL | testThumbnails | Exception caught - junit.framework.AssertionFailedError: 5 INFO TEST-UNEXPECTED-FAIL | testThumbnails | Top site thumbnail updated for HTTP 200 - got -1, expected -16711936 7 INFO TEST-END | testThumbnails | finished in 39471ms }
Whiteboard: [orange]
Summary: Intermittent testThumbnails | Top site thumbnail updated for HTTP 200 - got -1, expected -16711936 → Intermittent testThumbnails | Top site thumbnail updated for HTTP 200 - got -1 (or 0), expected -16711936
Test disabled for too many intermittent failures: https://hg.mozilla.org/integration/mozilla-inbound/rev/b8fc8436a0c6
Whiteboard: [test disabled][leave open]
I added logging to the ThumbnailTest to see what colors are encountered and when. Immediately prior to the failing test ("Top site thumbnail updated for HTTP 200"), ThumbnailTest usually finds something like this: ThumbnailTest: color == ffffffff ThumbnailTest: color == ffffffff ThumbnailTest: color == ffffffff ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == ff00ff00 So, initially, the thumbnail color is 0xffffffff (maybe -1 / not found), then after 300 or 400 ms, the thumbnail color is 0 for another 200 ms or so, and then the expected color is found. This seems reasonable. There is some variability in the timing, but in all of my tests (locally, on a Tegra board), the expected thumbnail color was found in under 1000 ms. We wait for up to 5000 ms, so I don't see how this is failing. More tests on try: https://tbpl.mozilla.org/?tree=Try&rev=8db09a53dabf https://tbpl.mozilla.org/?tree=Try&rev=c03417242976
try runs reproduced the problem. https://tbpl.mozilla.org/php/getParsedLog.php?id=18479700&tree=Try&full=1#error0 shows 0 INFO SimpleTest START 1 INFO TEST-START | testThumbnails 2 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=changeColor should equal http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=changeColor 3 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=do404 should equal http://mochi.test:8888/tests/robocop/robocop_404.sjs?type=do404 4 INFO TEST-PASS | testThumbnails | Awesomebar URL typed properly - about:home should equal about:home ThumbnailTest: color == ffffffff ThumbnailTest: color == ffffffff ThumbnailTest: color == ffffffff ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0 ThumbnailTest: color == 0
Related to bug 819953, 829059, 827248, 826387, 826064?
819953 and 829059 have been resolved, but the failure persists: https://tbpl.mozilla.org/?tree=Try&rev=3df2ed5559bd I'll check again once other thumbnail bugs have been resolved.
:bnicholson -- can you revisit? I'd like to see this test running and passing consistently, or if it is not viable, deleted completely.
Assignee: nobody → bnicholson
Attached patch Fix testThumbnails (obsolete) — Splinter Review
Needed a couple of important fixes: 1) View's methods are called in several places, so that code must run on the UI thread 2) The thumbnail runnable is fired 500ms after a document stop, but loadUrl() waits only for DOMContentLoaded. Document stop happens after DOMContentLoaded (sometimes several seconds later on slow devices), so we were continuing too early. There are still "Awesomebar URL typed properly" failures in Android 4.0 that need to be first; I filed bug 879505 for these.
Attachment #758208 - Flags: review?(gbrown)
Depends on: 879505
Comment on attachment 758208 [details] [diff] [review] Fix testThumbnails Review of attachment 758208 [details] [diff] [review]: ----------------------------------------------------------------- r+ on condition that the test is not enabled. ::: mobile/android/base/tests/robocop.ini @@ +23,4 @@ > [testBrowserProvider] > [testSearchSuggestions] > [testSharedPreferences] > +[testThumbnails] We cannot enable this without a fix for bug 879505. Maybe change the comment here to reference the new bug.
Attachment #758208 - Flags: review?(gbrown) → review+
After pushing to try, the previous patch didn't work so well. The waiting for document stop was kind of hacky, and there were a lot of failures: https://tbpl.mozilla.org/?tree=Try&rev=fb7e742c15e7 Additionally, that patch still had arbitrary timeouts in the test, which are best avoided if possible. I tried another approach that seems to work much better: instead of waiting an arbitrary amount of time and hoping the runnable ran, we can open the tabs tray and verify that the thumbnail is updated there before continuing. As a bonus, this also allows us to test the tabs tray thumbnail behavior since it is different from about:home (tabs tray thumbnails should always show the live view of the page, even if thumbnail isn't saved to the db). Try results: https://tbpl.mozilla.org/?tree=Try&rev=5d8ea688dcf0 I noticed that in the tabs tray, the thumbnail from the previously visited page is shown until the current page's thumbnail has been updated. To prevent the thumbnail from bleeding through to the next page and generating false positives in the test, I changed the test to use four distinct colors. changeColor now switches from green->red, and do404 switches from blue->yellow. The 60 second timeout for the tabs tray seems absurdly long, but the original timeout I tried, 20 seconds, still wasn't enough on ARMv6: https://tbpl.mozilla.org/?tree=Try&rev=cba337e2bfbc. Not sure why it's taking so long -- perhaps something we can address in a performance test. There's still a failure with the latest push that concerns me: "Top site thumbnail not updated for HTTP 404 - got -256, expected -16776961". Looking at the screenshot, do404 shows yellow on about:home when blue is expected. This appears to be an actual in-product bug since an HTTP 404 should never update the thumbnail in the database.
Attachment #758208 - Attachment is obsolete: true
Attachment #759398 - Flags: review?(gbrown)
Comment on attachment 759398 [details] [diff] [review] Fix testThumbnails, v2 Review of attachment 759398 [details] [diff] [review]: ----------------------------------------------------------------- This looks good - thanks. > There's still a failure with the latest push that concerns me Me too. It looks like it happens rarely, but any intermittent failure creates more work for the sheriffs, more bugmail, etc. I recommend that you not enable testThumbnails until this last issue is sorted out. (Or possibly disable that one assertion.) ::: mobile/android/base/tests/testThumbnails.java.in @@ +31,5 @@ > > + // The thumbnail update gets posted to a shared background thread, so use a > + // high timeout value in case other operations (like database accesses) are > + // delaying the runnable. > + static final private int THUMBNAIL_UPDATE_TIMEOUT = 60000; This does seem absurd, as you say. Consider adding a dumpLog warning message when the test waits more than ~15 seconds -- that might help us track the issue.
Attachment #759398 - Flags: review?(gbrown) → review+
Assignee: bnicholson → nobody
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Mass-closing old bugs I filed that have not had recent activity/no longer affect me.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INCOMPLETE
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: