Closed Bug 915350 Opened 12 years ago Closed 5 years ago

Intermittent testBookmarklets,testHistory,testTabHistory,testBookmarkKeyword | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01

Categories

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

Product:
Firefox for Android Graveyard
Component:
Awesomescreen
Platform:
ARM
Android
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE
Milestone:
Firefox 27

People

(Reporter: RyanVM, Unassigned)

References

Details

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

Attachments

(2 files)

Patch: increase timeout to 4500
1.25 KB, patch
gbrown
: review+
Details | Diff | Splinter Review
test fix
9.81 KB, patch
gbrown
: review+
Details | Diff | Splinter Review
https://tbpl.mozilla.org/php/getParsedLog.php?id=27705779&tree=Fx-Team Android 2.2 Tegra fx-team opt test robocop-1 on 2013-09-11 08:14:15 PDT for push a1a846de1a8a slave: tegra-094 0 INFO SimpleTest START 1 INFO TEST-START | testBookmarklets EventExpecter: no longer listening for Gecko:Ready 2 INFO TEST-PASS | testBookmarklets | waiting for urlbar text to gain focus - urlbar text gained focus 3 INFO TEST-PASS | testBookmarklets | URL typed properly - http://mochi.test:8888/tests/robocop/robocop_blank_01.html should equal http://mochi.test:8888/tests/robocop/robocop_blank_01.html EventExpecter: no longer listening for DOMContentLoaded waitForCondition timeout after 3000 ms. 4 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 Exception caught during test! junit.framework.AssertionFailedError: 4 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 at junit.framework.Assert.fail(Assert.java:47) at org.mozilla.fennec.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:111) at org.mozilla.fennec.FennecMochitestAssert.ok(FennecMochitestAssert.java:140) at org.mozilla.fennec.FennecMochitestAssert.is(FennecMochitestAssert.java:146) at org.mozilla.fennec.tests.BaseTest.verifyPageTitle(BaseTest.java:528) at org.mozilla.fennec.tests.testBookmarklets.testBookmarklets(testBookmarklets.java:26) 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:162) 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) 5 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Exception caught - junit.framework.AssertionFailedError: 4 INFO TEST-UNEXPECTED-FAIL | testBookmarklets | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 6 INFO TEST-END | testBookmarklets | finished in 36127ms 7 INFO TEST-START | Shutdown 8 INFO Passed: 2 9 INFO Failed: 2 10 INFO Todo: 0 11 INFO SimpleTest FINISHED
https://tbpl.mozilla.org/php/getParsedLog.php?id=27705526&tree=Fx-Team
Summary: Intermittent testBookmarklets | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 → Intermittent testBookmarklets,testHistory | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01
https://tbpl.mozilla.org/php/getParsedLog.php?id=27708995&tree=Mozilla-Inbound https://tbpl.mozilla.org/php/getParsedLog.php?id=27712012&tree=Mozilla-Inbound
Summary: Intermittent testBookmarklets,testHistory | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 → Intermittent testBookmarklets,testHistory,testTabHistory | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01
https://tbpl.mozilla.org/php/getParsedLog.php?id=27724058&tree=Fx-Team Mark, this seems to be a very frequent, recent regression. Can someone on your team please look at this ASAP?
Flags: needinfo?(mark.finkle)
Summary: Intermittent testBookmarklets,testHistory,testTabHistory | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 → Intermittent testBookmarklets,testHistory,testTabHistory,testBookmarkKeyword | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01
Looks like a possible problem with verifyPageTitle. Regression caused by bug 912590?
Flags: needinfo?(liuche)
(In reply to :Margaret Leibovic from comment #6) > Looks like a possible problem with verifyPageTitle. Regression caused by bug > 912590? That does seem likely, considering that the url is verified as being typed correctly, but the urlbar text is still the url, instead of the page title, and this happens much more frequently on the (slower) 2.2 devices. I'm looking over those patches again; having some trouble verifying locally.
Assignee: nobody → liuche
Flags: needinfo?(liuche)
Looking at the logs a little more carefully, this is definitely what's happening. waitForCondition timeout after 3000 ms. 6 INFO TEST-UNEXPECTED-FAIL | testBookmarkKeyword | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 Exception caught during test! junit.framework.AssertionFailedError: 6 INFO TEST-UNEXPECTED-FAIL | testBookmarkKeyword | Page title is correct - got http://mochi.test:8888/tests/robocop/robocop_blank_01.html, expected Browser Blank Page 01 at junit.framework.Assert.fail(Assert.java:47) This is failing because we're timing out waiting for the url to switch to the title (on load completion). I'm not entirely sure why we aren't timing out waiting for DOMContentLoaded instead though... It's possible that the Robotium 4.2 APIs are not as good as the old BooleanTest that we were using; however, these failures also started appearing a day or two after bug 912590 landed, so it could be that we are just taking more time to load pages on Android 2.2. I'll experiment with some timeouts, and see what works, and then upload a patch.
I've been running tests on try, and a timeout of 4500 seems to avoid any of the oranges of this bug. https://tbpl.mozilla.org/?tree=Try&rev=1002cc99bd15 For some reason, a lot of these orange reports don't have screenshots. Going through some of them, the full log from comment #12 has a screenshot from the failure does contain a screenshot (search for data:image), but the screenshot displays the right text (content is black, though). I'll upload the 4500 timeout patch and we can land that and reopen this bug if this is still a problem. I'm not convinced this is simply a timeout problem though.
Comment on attachment 804813 [details] [diff] [review] Patch: increase timeout to 4500 Review of attachment 804813 [details] [diff] [review]: ----------------------------------------------------------------- Reluctantly...(I don't have a better idea.)
Attachment #804813 - Flags: review?(gbrown) → review+
Landed on fx-team - let's see if this fixes this orange. I'll also do some more investigation to see if there's another way to fix this, better than just increasing the timeout. https://hg.mozilla.org/integration/fx-team/rev/e1dfb1746f96
https://hg.mozilla.org/mozilla-central/rev/e1dfb1746f96
Status: NEW → RESOLVED
Closed: 12 years ago
Flags: in-testsuite-
Resolution: --- → FIXED
Target Milestone: --- → Firefox 27
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Most of these don't have screenshots, unfortunately. Comment #152 contains one, but the url is only partially typed in that screenshot. This means that at least some of these oranges are due to timeouts - it's still worth trying to find out why some of these are taking so much longer to load. The correct approach is to listen for the page to finish loading, with a timeout.
testBookmarklets, testHistory, testTabHistory & testBookmarkKeyword disabled until we get these failures under control (sorry): https://hg.mozilla.org/integration/mozilla-inbound/rev/54d4889555ca
Whiteboard: [test disabled][leave open]
Flags: needinfo?(mark.finkle)
Attached patch test fix — — Splinter Review
Since a lot of tests that extend AboutHomeTest need to use loadAndPaint changing AboutHomeTest to extend PixelTest. Changing the inputAndLoadUrl to loadAndPaint solves the issues for me locally. "DOMContentLoaded" returns way to fast and the title check is done while the page is still being painted.
Attachment #815367 - Flags: review?(gbrown)
(In reply to Adrian Tamas (:AdrianT) from comment #208) > Created attachment 815367 [details] [diff] [review] > test fix > > Since a lot of tests that extend AboutHomeTest need to use loadAndPaint > changing AboutHomeTest to extend PixelTest. > Changing the inputAndLoadUrl to loadAndPaint solves the issues for me > locally. "DOMContentLoaded" returns way to fast and the title check is done > while the page is still being painted. Tryrun for this: https://tbpl.mozilla.org/?tree=Try&rev=38b87d0535cd
Even without changes, I see these tests running reliably now: https://tbpl.mozilla.org/?tree=Try&rev=eba988dc22c5 At least testBookmarklets, testBookmarkKeyword, testTabHistory (testHistory still fails). Thoughts on enabling?
Flags: needinfo?(emorley)
Flags: needinfo?(adrian.tamas)
Works for me :-)
Flags: needinfo?(emorley)
Comment on attachment 815367 [details] [diff] [review] test fix Review of attachment 815367 [details] [diff] [review]: ----------------------------------------------------------------- I think this is reasonable, and certainly seems effective. I have slight misgivings about making everything (many tests) use loadAndPaint, since that includes a fairly long wait for paint completion, and our method of waiting for paint completion is not optimal. I would really like to have a simple event that says, "url X has finished loading; the page is displayed and the ui has been updated". Until then...
Attachment #815367 - Flags: review?(gbrown) → review+
(In reply to Geoff Brown [:gbrown] from comment #213) > Comment on attachment 815367 [details] [diff] [review] > test fix > > Review of attachment 815367 [details] [diff] [review]: > ----------------------------------------------------------------- > > I think this is reasonable, and certainly seems effective. > > I have slight misgivings about making everything (many tests) use > loadAndPaint, since that includes a fairly long wait for paint completion, > and our method of waiting for paint completion is not optimal. I would > really like to have a simple event that says, "url X has finished loading; > the page is displayed and the ui has been updated". Until then... We can wait and see if the fail is fixed by just re-enabling the tests, if not we can add this fix. Although for me locally on the LG Optimus 2X (Android 2.2) without the patch the tests fail. Regarding the loadAndPaint...at the moment it seems the most reliable way to load a website and wait for it to load completely. As I said before the DOMContentLoaded event is received way to early in the loading and it takes way to long after that for page paint to complete. I have talked in the past with Mark Finkle on irc about something to check when a webpage finishes loading but as he pointed out some websites with dynamic content that may never fully end rendering so there is no event for load complete.
Flags: needinfo?(adrian.tamas)
Blocks: 912343
testBookmark disabled on inbound & Aurora. https://hg.mozilla.org/integration/mozilla-inbound/rev/f606614e2359 https://hg.mozilla.org/releases/mozilla-aurora/rev/7ee062b4c13a testBookmark, testBookmarklets, testBookmarkKeyword, testHistory, and testTabHistory disabled on Beta. https://hg.mozilla.org/releases/mozilla-beta/rev/53eb79e74521
I believe I solved this (however, with a hack) in the UITest framework from bug 910859 comment 69. I'll briefly explain my solution, in case we want to port this to BaseTest (though, alternatively, we can port these tests to UITest). The problem is the title bar is briefly set to the URL before the real title is received from the server. The event to update the title fires on the page load event, which is the same event we wait on for the page to load. When the assertion fires, it is a race to see if the title has changed first or the page has loaded. As such, in my waitForPageLoad [1], after the page load event fires, I verify that the title does not look like "http://...", and ensure the title is different than it was before the page load event was triggered. The interface I use to do this is [2]. This check will eventually time out [3] so if there is an error retrieving the title or the title does not load quickly enough, the assertion will still fail. It's hard to explain well - hopefully the source code can clear up anything that's not clear. [1]: https://github.com/mcomella/new-ui-testing/blob/e5b43f619b0a0db84b4600877c3cb8eaa5e54f27/helpers/WaitHelper.java#L71 [2]: https://github.com/mcomella/new-ui-testing/blob/e5b43f619b0a0db84b4600877c3cb8eaa5e54f27/helpers/WaitHelper.java#L124 [3]: https://github.com/mcomella/new-ui-testing/blob/e5b43f619b0a0db84b4600877c3cb8eaa5e54f27/helpers/WaitHelper.java#L99
I may have to redact comment 319 - I'm getting intermittents (but only only armv6). I'll be solving this in bug 938969 and will report back when I finish.
I think I got it right with bug 910859 comment 93 (part 2's patch) - we should be waiting on both the "DOMContentLoaded" and "DOMTitleChanged" events on page load.
Okay, seemingly fixed with bug 946656. comment 319 was correct - I just implemented it incorrectly. It may be beneficial to also wait for DOMTitleChanged because that is not guarantee to fire shortly after DOMContentLoaded.
See Also: → 876095
In bug 1111729, I'm going to change the default titlebar preference to show the page URL instead of the page title, and I'm updating all the robocop tests that currently check the page title. This failure probably reflects some deeper underlying issues, but it won't manifest itself in this same failure anymore if we're not checking the page title.
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
We have completed our launch of our new Firefox on Android. The development of the new versions use GitHub for issue tracking. If the bug report still reproduces in a current version of [Firefox on Android nightly](https://play.google.com/store/apps/details?id=org.mozilla.fenix) an issue can be reported at the [Fenix GitHub project](https://github.com/mozilla-mobile/fenix/). If you want to discuss your report please use [Mozilla's chat](https://wiki.mozilla.org/Matrix#Connect_to_Matrix) server https://chat.mozilla.org and join the [#fenix](https://chat.mozilla.org/#/room/#fenix:mozilla.org) channel.
Status: REOPENED → RESOLVED
Closed: 12 years ago → 5 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

Creator:
Created:
Updated:
Size: