Closed Bug 770483 Opened 13 years ago Closed 13 years ago

Intermittent Robocop testAboutPage | GeckoEventExpecter - blockForEvent timeout: Tab:Added

Categories

(Firefox for Android Graveyard :: General, defect)

Product:
Firefox for Android Graveyard
Component:
General
Platform:
ARM
Android
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED
Milestone:
Firefox 21

People

(Reporter: emorley, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

diagnostic patch
2.94 KB, patch
jmaher
: review+
Details | Diff | Splinter Review
enable testAboutPage
812 bytes, patch
emorley
: review+
Details | Diff | Splinter Review
Android Tegra 250 mozilla-inbound opt test robocop on 2012-07-03 03:48:45 PDT for push 10fad54737f6 slave: tegra-120 https://tbpl.mozilla.org/php/getParsedLog.php?id=13189089&tree=Mozilla-Inbound { FIRE PROC: '"MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpMaTCi9pidlog,XPCOM_MEM_BLOAT_LOG=/mnt/sdcard/tests/profile/runtests_leaks.log" am instrument -w -e class org.mozilla.fennec.tests.testAboutPage org.mozilla.roboexample.test/android.test.InstrumentationTestRunner' INFO | automation.py | Application pid: 0 0 INFO SimpleTest START 1 INFO TEST-START | testAboutPage 2 INFO TEST-UNEXPECTED-FAIL | testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready Exception caught during test! junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 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:137) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:141) at org.mozilla.fennec.tests.testAboutPage.testAboutPage(testAboutPage.java:15) 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:93) 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) 3 INFO TEST-UNEXPECTED-FAIL | testAboutPage | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 4 INFO TEST-END | testAboutPage | finished in 90148ms 5 INFO TEST-START | Shutdown 6 INFO Passed: 0 7 INFO Failed: 2 8 INFO Todo: 0 9 INFO SimpleTest FINISHED INFO | automation.py | Application ran for: 0:02:19.438252 INFO | automation.py | Reading PID log: /tmp/tmpMaTCi9pidlog getting files in '/mnt/sdcard/tests/profile/minidumps/' WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected! INFO | runtests.py | Running tests: end. removing file: /mnt/sdcard/tests/logs/mochitest.log Warning: cleaning up pidfile '/builds/tegra-120/test/../runtestsremote.pid' was unsuccessful from the test harness INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/roboextender@mozilla.org to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/specialpowers to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/worker to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/workerbootstrap to /tmp/tmpNVZWWd. pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile args: ['/builds/tegra-120/test/build/hostutils/bin/xpcshell', '-g', '/builds/tegra-120/test/build/hostutils/xre', '-v', '170', '-f', './httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpXdOuKy';const _SERVER_PORT = '30120'; const _SERVER_ADDR = '10.250.48.214'; const _TEST_PREFIX = undefined;", '-f', './server.js'] INFO | runtests.py | Server pid: 78313 pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile INFO | runtests.py | Running tests: start. FIRE PROC: '"MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmp77Fgd1pidlog,XPCOM_MEM_BLOAT_LOG=/mnt/sdcard/tests/profile/runtests_leaks.log" am instrument -w -e class org.mozilla.fennec.tests.testWebContentContextMenu org.mozilla.roboexample.test/android.test.InstrumentationTestRunner' INFO | automation.py | Application pid: 0 0 INFO SimpleTest START 1 INFO TEST-START | testWebContentContextMenu 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready Exception caught during test! junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 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:137) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:141) at org.mozilla.fennec.tests.testWebContentContextMenu.testWebContentContextMenu(testWebContentContextMenu.java:15) 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:93) 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) 3 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testWebContentContextMenu | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 4 INFO TEST-END | testWebContentContextMenu | finished in 90137ms 5 INFO TEST-START | Shutdown 6 INFO Passed: 0 7 INFO Failed: 2 8 INFO Todo: 0 9 INFO SimpleTest FINISHED INFO | automation.py | Application ran for: 0:02:19.407081 INFO | automation.py | Reading PID log: /tmp/tmp77Fgd1pidlog getting files in '/mnt/sdcard/tests/profile/minidumps/' WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected! INFO | runtests.py | Running tests: end. removing file: /mnt/sdcard/tests/logs/mochitest.log Warning: cleaning up pidfile '/builds/tegra-120/test/../runtestsremote.pid' was unsuccessful from the test harness INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/roboextender@mozilla.org to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/specialpowers to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/worker to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/workerbootstrap to /tmp/tmpNVZWWd. pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile args: ['/builds/tegra-120/test/build/hostutils/bin/xpcshell', '-g', '/builds/tegra-120/test/build/hostutils/xre', '-v', '170', '-f', './httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpVufwaz';const _SERVER_PORT = '30120'; const _SERVER_ADDR = '10.250.48.214'; const _TEST_PREFIX = undefined;", '-f', './server.js'] INFO | runtests.py | Server pid: 78365 pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile INFO | runtests.py | Running tests: start. FIRE PROC: '"MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpaUn3gWpidlog,XPCOM_MEM_BLOAT_LOG=/mnt/sdcard/tests/profile/runtests_leaks.log" am instrument -w -e class org.mozilla.fennec.tests.testPasswordProvider org.mozilla.roboexample.test/android.test.InstrumentationTestRunner' INFO | automation.py | Application pid: 0 0 INFO SimpleTest START 1 INFO TEST-START | testPasswordProvider 2 INFO TEST-UNEXPECTED-FAIL | testPasswordProvider | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready Exception caught during test! junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPasswordProvider | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 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:137) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:141) at org.mozilla.fennec.tests.testPasswordProvider.testPasswordProvider(testPasswordProvider.java:35) 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:93) 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) 3 INFO TEST-UNEXPECTED-FAIL | testPasswordProvider | Exception caught - junit.framework.AssertionFailedError: 2 INFO TEST-UNEXPECTED-FAIL | testPasswordProvider | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 4 INFO TEST-END | testPasswordProvider | finished in 90137ms 5 INFO TEST-START | Shutdown 6 INFO Passed: 0 7 INFO Failed: 2 8 INFO Todo: 0 9 INFO SimpleTest FINISHED INFO | automation.py | Application ran for: 0:02:19.448050 INFO | automation.py | Reading PID log: /tmp/tmpaUn3gWpidlog getting files in '/mnt/sdcard/tests/profile/minidumps/' WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected! INFO | runtests.py | Running tests: end. removing file: /mnt/sdcard/tests/logs/mochitest.log Warning: cleaning up pidfile '/builds/tegra-120/test/../runtestsremote.pid' was unsuccessful from the test harness INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/roboextender@mozilla.org to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/specialpowers to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/worker to /tmp/tmpNVZWWd. INFO | runtests.py | Installing extension at /builds/tegra-120/test/build/tests/mochitest/extensions/workerbootstrap to /tmp/tmpNVZWWd. pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile args: ['/builds/tegra-120/test/build/hostutils/bin/xpcshell', '-g', '/builds/tegra-120/test/build/hostutils/xre', '-v', '170', '-f', './httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpRdYF6F';const _SERVER_PORT = '30120'; const _SERVER_ADDR = '10.250.48.214'; const _TEST_PREFIX = undefined;", '-f', './server.js'] INFO | runtests.py | Server pid: 78517 pushing directory: /tmp/tmpNVZWWd to /mnt/sdcard/tests/profile INFO | runtests.py | Running tests: start. FIRE PROC: '"MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpYHd8iXpidlog,XPCOM_MEM_BLOAT_LOG=/mnt/sdcard/tests/profile/runtests_leaks.log" am instrument -w -e class org.mozilla.fennec.tests.testPasswordEncrypt org.mozilla.roboexample.test/android.test.InstrumentationTestRunner' INFO | automation.py | Application pid: 0 0 INFO SimpleTest START 1 INFO TEST-START | testPasswordEncrypt 2 INFO TEST-PASS | testPasswordEncrypt | Found a content resolver - android.app.ContextImpl$ApplicationContentResolver@443297e8 should not equal null 3 INFO TEST-UNEXPECTED-FAIL | testPasswordEncrypt | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready Exception caught during test! junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testPasswordEncrypt | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready 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:137) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:141) at org.mozilla.fennec.tests.testPasswordEncrypt.testPasswordEncrypt(testPasswordEncrypt.java:31) 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:93) 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) 4 INFO TEST-UNEXPECTED-FAIL | testPasswordEncrypt | Exception caught - junit.framework.AssertionFailedError: 3 INFO TEST-UNEXPECTED-FAIL | testPasswordEncrypt | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready (...and more) }
Ordinarily I'd say that this was one bug which was WFM not long after it was filed, due to a backout or a followup or whoknowswhat, and then another bug due to something that landed Friday afternoon which should be filed as a new separate bug, but in this case, after so much love and affection has been lavished on this bug, we might as well just morph it to the new Tab:Added timeout.
Summary: Intermittent Robocop testAboutPage | GeckoEventExpecter - blockForEvent timeout: Gecko:Ready → Intermittent Robocop testAboutPage | GeckoEventExpecter - blockForEvent timeout: Tab:Added
Assignee: nobody → gbrown
Attached patch diagnostic patch — — Splinter Review
I cannot see why this test is failing, but I find myself wondering if the menu manipulations are working. This patch adds additional logging to verify each step of the menu clicks leading up to this failure. I opted for dumpLog() rather than is()-like assertions since these new checks are not directly testing about: page functionality, and also because I want the test to keep failing the same way. Here's the new output: 0 INFO SimpleTest START 1 INFO TEST-START | testAboutPage 2 INFO TEST-PASS | testAboutPage | Awesomebar URL typed properly - about: should equal about: 3 INFO TEST-PASS | testAboutPage | Got the awesomebar - org.mozilla.fennec_mozdev.FennecNativeElement@48619940 should not equal null 4 INFO TEST-PASS | testAboutPage | page title match - Expected /About (Fennec|Nightly|Aurora|Firefox|Firefox Beta)/, got "About Fennec" 5 INFO TEST-PASS | testAboutPage | Awesomebar 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 found More item in menu found Settings item in menu found About... title text 6 INFO TEST-PASS | testAboutPage | Got the awesomebar - org.mozilla.fennec_mozdev.FennecNativeElement@4876b458 should not equal null 7 INFO TEST-PASS | testAboutPage | page title match - Expected /About (Fennec|Nightly|Aurora|Firefox|Firefox Beta)/, got "About Fennec" 8 INFO TEST-END | testAboutPage | finished in 32205ms 9 INFO TEST-START | Shutdown 10 INFO Passed: 6 11 INFO Failed: 0 12 INFO Todo: 0 13 INFO SimpleTest FINISHED
Attachment #662192 - Flags: review?(jmaher)
Comment on attachment 662192 [details] [diff] [review] diagnostic patch Review of attachment 662192 [details] [diff] [review]: ----------------------------------------------------------------- good idea, thanks for the patch. ::: mobile/android/base/tests/testAboutPage.java.in @@ +4,5 @@ > import @ANDROID_PACKAGE_NAME@.*; > import android.app.Activity; > import android.util.Log; > > +/* nit: extra whitepace here.
Attachment #662192 - Flags: review?(jmaher) → review+
Whiteboard: [orange] → [orange] [leave open]
The latest failure with new diagnostics suggests that the menu clicks are working: 1 INFO TEST-START | testAboutPage 2 INFO TEST-PASS | testAboutPage | Awesomebar URL typed properly - about: should equal about: 3 INFO TEST-PASS | testAboutPage | Got the awesomebar - org.mozilla.fennec.FennecNativeElement@4850faf0 should not equal null 4 INFO TEST-PASS | testAboutPage | page title match - Expected /About (Fennec|Nightly|Aurora|Firefox|Firefox Beta)/, got "About Nightly" 5 INFO TEST-PASS | testAboutPage | Awesomebar 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 found More item in menu found Settings item in menu found About... title text Dumping ALL the threads!
I reproduced on try with further diagnostics and found that in the failure cases, the page is not being loaded. The page is not loaded because the click on the link is not received: LinkPreference.onClick is not invoked (I don't know why yet).
Whiteboard: [orange] [leave open] → [leave open]
See Also: → 817440
Top-orange; disabled for now: https://hg.mozilla.org/integration/mozilla-inbound/rev/e5e7bb731ca1
Whiteboard: [leave open] → [test disabled][leave open]
I have not been able to find anything wrong with this test, and now I cannot reproduce the failures. https://tbpl.mozilla.org/?tree=Try&rev=73f6f1c598d8 has 300 runs of testAboutPage with no failures. Any objection to enabling?
Attachment #712916 - Flags: review?(emorley)
Comment on attachment 712916 [details] [diff] [review] enable testAboutPage wfm, we can always re-evaluate should this occur again :-)
Attachment #712916 - Flags: review?(emorley) → review+
Enabled: https://hg.mozilla.org/integration/mozilla-inbound/rev/ae25316d0a24
Whiteboard: [test disabled][leave open]
https://hg.mozilla.org/mozilla-central/rev/ae25316d0a24
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 21
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: