Closed
Bug 880234
Opened 11 years ago
Closed 11 years ago
Intermittent testDeviceSearchEngine | GeckoEventExpecter - blockForEvent timeout: Robocop:Status
Categories
(Firefox for Android Graveyard :: General, defect)
Tracking
(Not tracked)
RESOLVED
FIXED
Firefox 24
People
(Reporter: RyanVM, Assigned: nalexander)
Details
(Keywords: intermittent-failure)
Attachments
(1 file, 1 obsolete file)
1.22 KB,
patch
|
mfinkle
:
review+
|
Details | Diff | Splinter Review |
https://tbpl.mozilla.org/php/getParsedLog.php?id=23844512&tree=Mozilla-Inbound Android Tegra 250 mozilla-inbound opt test robocop-2 on 2013-06-05 21:22:57 PDT for push a6912e70b705 slave: tegra-152 0 INFO SimpleTest START 1 INFO TEST-START | testDeviceSearchEngine EventExpecter: no longer listening for Gecko:Ready Registered listener for Robocop:Status Loading JavaScript test from http://mochi.test:8888/tests/robocop/robocop_javascript.html?path=testDeviceSearchEngine.js 2 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 1 pending 3 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 2 pending 4 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Starting test_default 5 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 3 pending 6 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Loading search engine 7 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 4 pending 8 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 4 finished 9 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 3 finished 10 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 2 finished 11 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Observer: engine-changed for Test search engine 12 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Observer: engine-added for Test search engine 13 INFO TEST-PASS | testDeviceSearchEngine | testDeviceSearchEngine.js - [check_submission : 22] http://example.com/search?q=foo == http://example.com/search?q=foo 14 INFO TEST-PASS | testDeviceSearchEngine | testDeviceSearchEngine.js - [check_submission : 22] http://example.com/search/tablet?q=foo == http://example.com/search/tablet?q=foo 15 INFO TEST-PASS | testDeviceSearchEngine | testDeviceSearchEngine.js - [check_submission : 22] http://example.com/search/phone?q=foo == http://example.com/search/phone?q=foo 16 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Device: phone 17 INFO TEST-PASS | testDeviceSearchEngine | testDeviceSearchEngine.js - [check_submission : 22] http://example.com/search/phone?q=foo == http://example.com/search/phone?q=foo 18 INFO TEST-INFO | testDeviceSearchEngine | (xpcshell/head.js) - test 1 finished 19 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Observer: engine-current for Test search engine 20 INFO TEST-INFO | testDeviceSearchEngine | testDeviceSearchEngine.js - Observer: engine-loaded for Test search engine Dumping ALL the threads! Thread[Binder Thread #2,5,main] dalvik.system.NativeStart.run(Native Method) Thread[Compiler,5,system] dalvik.system.NativeStart.run(Native Method) Thread[Thread-17,5,main] dalvik.system.NativeStart.run(Native Method) Thread[HeapWorker,5,system] dalvik.system.NativeStart.run(Native Method) Thread[Timer-0,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:326) java.util.Timer$TimerImpl.run(Timer.java:243) Thread[Signal Catcher,5,system] dalvik.system.NativeStart.run(Native Method) Thread[pool-1-thread-1,5,main] java.lang.Object.wait(Native Method) java.lang.Thread.parkFor(Thread.java:1535) java.lang.LangAccessImpl.parkFor(LangAccessImpl.java:48) sun.misc.Unsafe.park(Unsafe.java:317) java.util.concurrent.locks.LockSupport.park(LockSupport.java:131) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1996) java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:359) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1001) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:561) java.lang.Thread.run(Thread.java:1096) Thread[GeckoANRReporter,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:288) android.os.MessageQueue.next(MessageQueue.java:146) android.os.Looper.loop(Looper.java:110) org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:102) java.lang.Thread.run(Thread.java:1096) Thread[GeckoBackgroundThread,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:288) android.os.MessageQueue.next(MessageQueue.java:146) android.os.Looper.loop(Looper.java:110) org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:32) Thread[Gecko,5,main] org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:317) org.mozilla.gecko.GeckoThread.run(GeckoThread.java:113) Thread[JDWP,5,system] dalvik.system.NativeStart.run(Native Method) Thread[Instr: org.mozilla.fennec.FennecInstrumentationTestRunner,5,main] dalvik.system.VMStack.getThreadStackTrace(Native Method) java.lang.Thread.getStackTrace(Thread.java:788) java.lang.Thread.getAllStackTraces(Thread.java:669) org.mozilla.fennec.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:411) org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:147) org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:128) org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:207) org.mozilla.fennec.tests.JavascriptTest.testJavascript(JavascriptTest.java:117) java.lang.reflect.Method.invokeNative(Native Method) java.lang.reflect.Method.invoke(Method.java:521) android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204) android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194) android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186) org.mozilla.fennec.tests.BaseTest.runTest(BaseTest.java:131) junit.framework.TestCase.runBare(TestCase.java:127) junit.framework.TestResult$1.protect(TestResult.java:106) junit.framework.TestResult.runProtected(TestResult.java:124) junit.framework.TestResult.run(TestResult.java:109) junit.framework.TestCase.run(TestCase.java:118) android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169) android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154) android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:520) android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1447) Thread[RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@48674d08,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:326) java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:107) java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:80) org.apache.http.impl.conn.tsccm.RefQueueWorker.run(RefQueueWorker.java:102) java.lang.Thread.run(Thread.java:1096) Thread[main,5,main] java.lang.Object.wait(Native Method) java.lang.Object.wait(Object.java:288) android.os.MessageQueue.next(MessageQueue.java:146) android.os.Looper.loop(Looper.java:110) android.app.ActivityThread.main(ActivityThread.java:4627) java.lang.reflect.Method.invokeNative(Native Method) java.lang.reflect.Method.invoke(Method.java:521) com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:868) com.android.internal.os.ZygoteInit.main(ZygoteInit.java:626) dalvik.system.NativeStart.main(Native Method) Thread[Binder Thread #1,5,main] dalvik.system.NativeStart.run(Native Method) 21 INFO TEST-UNEXPECTED-FAIL | testDeviceSearchEngine | GeckoEventExpecter - blockForEvent timeout: Robocop:Status EventExpecter: no longer listening for Robocop:Status Unregistered listener for Robocop:Status Exception caught during test! junit.framework.AssertionFailedError: 21 INFO TEST-UNEXPECTED-FAIL | testDeviceSearchEngine | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 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.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:148) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:128) at org.mozilla.fennec.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:207) at org.mozilla.fennec.tests.JavascriptTest.testJavascript(JavascriptTest.java:117) 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:131) 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) 22 INFO TEST-UNEXPECTED-FAIL | testDeviceSearchEngine | Exception caught - junit.framework.AssertionFailedError: 21 INFO TEST-UNEXPECTED-FAIL | testDeviceSearchEngine | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 23 INFO TEST-END | testDeviceSearchEngine | finished in 109953ms 24 INFO TEST-START | Shutdown 25 INFO Passed: 19 26 INFO Failed: 2 27 INFO Todo: 0 28 INFO SimpleTest FINISHED
Comment 1•11 years ago
|
||
This problem is happening in JavaScriptTest. Have we seen this failure with any other tests?
Assignee | ||
Comment 2•11 years ago
|
||
(In reply to :Margaret Leibovic from comment #1) > This problem is happening in JavaScriptTest. Have we seen this failure with > any other tests? JavascriptTest waits for Robocop:Status messages from the test harness, which correspond to head.js output lines (xpcshell's head.js, slightly modified). That's how it knows when tests pass, or fail, or the suite ends. I'm not certain that do_test_pending() works with add_task() -- see http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/tests/testDeviceSearchEngine.js#51. Does that work with xpcshell? Otherwise, this could be a "real intermittent" -- for reasons unknown, Javascript -> Java messages do get lost.
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment 5•11 years ago
|
||
For some context, I based this test on an existing test: http://mxr.mozilla.org/mozilla-central/source/toolkit/components/search/tests/xpcshell/test_purpose.js But I copied Nick's use of add_task, instead of run_test. I can change that. No idea if it will make a difference or not.
Comment 6•11 years ago
|
||
This is a simple patch to switch to using run_test instead of add_task. Try runs are here: https://tbpl.mozilla.org/?tree=Try&rev=b38cb8ae49c7 So far it's looking green. I'll keep retriggering to look for intermittents.
Assignee: nobody → mark.finkle
Attachment #761594 -
Flags: review?(nalexander)
Assignee | ||
Comment 7•11 years ago
|
||
I see lots of use of do_test_pending() and do_test_finished(), but reading robocop_head.js suggests that such use is an abuse of the internals of how xpcshell launches child processes. This is the documented API, and works locally.
Attachment #761594 -
Attachment is obsolete: true
Attachment #761594 -
Flags: review?(nalexander)
Attachment #761759 -
Flags: review?(mark.finkle)
Assignee | ||
Updated•11 years ago
|
Assignee: mark.finkle → nalexander
Comment 8•11 years ago
|
||
Comment on attachment 761759 [details] [diff] [review] Use add_test in testDeviceSearchEngines. r=mfinkle This makes me think either way would work: https://developer.mozilla.org/en-US/docs/Writing_xpcshell-based_unit_tests#Async_tests Let's consider this cat successfully skinned
Attachment #761759 -
Flags: review?(mark.finkle) → review+
Assignee | ||
Comment 9•11 years ago
|
||
https://hg.mozilla.org/integration/mozilla-inbound/rev/3aa27583bd92
Assignee | ||
Updated•11 years ago
|
Status: NEW → ASSIGNED
Target Milestone: --- → Firefox 24
Comment 10•11 years ago
|
||
https://hg.mozilla.org/mozilla-central/rev/3aa27583bd92
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
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
•