Closed Bug 1049022 Opened 6 years ago Closed 5 years ago

Intermittent testAndroidLog | GeckoEventExpecter - blockForEvent timeout: Robocop:JS

Categories

(Firefox for Android :: General, defect)

x86
Android
defect
Not set
normal

Tracking

()

RESOLVED DUPLICATE of bug 1184186

People

(Reporter: RyanVM, Assigned: gbrown)

Details

(Keywords: intermittent-failure)

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

Android 4.2 x86 Emulator mozilla-inbound opt test androidx86-set-4 on 2014-08-05 09:25:12 PDT for push 8ecb3e5d5013
slave: talos-linux64-ix-031

09:59:36     INFO -  5 INFO SimpleTest START
09:59:36     INFO -  6 INFO TEST-START | testAndroidLog
09:59:36     INFO -  7 INFO TEST-PASS | testAndroidLog | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
09:59:36     INFO -  8 INFO EventExpecter: no longer listening for Gecko:Ready
09:59:36     INFO -  9 INFO Registered listener for Robocop:JS
09:59:36     INFO -  10 INFO Loading JavaScript test from http://mochi.test:8888/tests/robocop/robocop_javascript.html?path=testAndroidLog.js
09:59:36     INFO -  11 INFO Dumping ALL the threads!
09:59:36     INFO -  12 INFO Thread[Signal Catcher,5,system]
09:59:36     INFO -  13 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  14 INFO Thread[main,5,main]
09:59:36     INFO -  15 INFO android.os.MessageQueue.nativePollOnce(Native Method)
09:59:36     INFO -  16 INFO android.os.MessageQueue.next(MessageQueue.java:125)
09:59:36     INFO -  17 INFO android.os.Looper.loop(Looper.java:124)
09:59:36     INFO -  18 INFO android.app.ActivityThread.main(ActivityThread.java:5039)
09:59:36     INFO -  19 INFO java.lang.reflect.Method.invokeNative(Native Method)
09:59:36     INFO -  20 INFO java.lang.reflect.Method.invoke(Method.java:511)
09:59:36     INFO -  21 INFO com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:793)
09:59:36     INFO -  22 INFO com.android.internal.os.ZygoteInit.main(ZygoteInit.java:560)
09:59:36     INFO -  23 INFO dalvik.system.NativeStart.main(Native Method)
09:59:36     INFO -  24 INFO Thread[ReferenceQueueDaemon,5,system]
09:59:36     INFO -  25 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  26 INFO java.lang.Object.wait(Object.java:364)
09:59:36     INFO -  27 INFO java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
09:59:36     INFO -  28 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  29 INFO Thread[FinalizerDaemon,5,system]
09:59:36     INFO -  30 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  31 INFO java.lang.Object.wait(Object.java:401)
09:59:36     INFO -  32 INFO java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
09:59:36     INFO -  33 INFO java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
09:59:36     INFO -  34 INFO java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
09:59:36     INFO -  35 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  36 INFO Thread[Picasso-Dispatcher,5,main]
09:59:36     INFO -  37 INFO android.os.MessageQueue.nativePollOnce(Native Method)
09:59:36     INFO -  38 INFO android.os.MessageQueue.next(MessageQueue.java:125)
09:59:36     INFO -  39 INFO android.os.Looper.loop(Looper.java:124)
09:59:36     INFO -  40 INFO android.os.HandlerThread.run(HandlerThread.java:60)
09:59:36     INFO -  41 INFO Thread[Picasso-Idle,5,main]
09:59:36     INFO -  42 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  43 INFO java.lang.Thread.parkFor(Thread.java:1231)
09:59:36     INFO -  44 INFO sun.misc.Unsafe.park(Unsafe.java:323)
09:59:36     INFO -  45 INFO java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
09:59:36     INFO -  46 INFO java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
09:59:36     INFO -  47 INFO java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
09:59:36     INFO -  48 INFO java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
09:59:36     INFO -  49 INFO java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
09:59:36     INFO -  50 INFO java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
09:59:36     INFO -  51 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  52 INFO com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
09:59:36     INFO -  53 INFO Thread[Thread-110,5,main]
09:59:36     INFO -  54 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  55 INFO Thread[Instr: org.mozilla.gecko.FennecInstrumentationTestRunner,5,main]
09:59:36     INFO -  56 INFO dalvik.system.VMStack.getThreadStackTrace(Native Method)
09:59:36     INFO -  57 INFO java.lang.Thread.getStackTrace(Thread.java:591)
09:59:36     INFO -  58 INFO java.lang.Thread.getAllStackTraces(Thread.java:528)
09:59:36     INFO -  59 INFO org.mozilla.gecko.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:301)
09:59:36     INFO -  60 INFO org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:95)
09:59:36     INFO -  61 INFO org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:80)
09:59:36     INFO -  62 INFO org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:144)
09:59:36     INFO -  63 INFO org.mozilla.gecko.tests.JavascriptTest.testJavascript(JavascriptTest.java:47)
09:59:36     INFO -  64 INFO org.mozilla.gecko.tests.testAndroidLog.testJavascript(testAndroidLog.java:15)
09:59:36     INFO -  65 INFO java.lang.reflect.Method.invokeNative(Native Method)
09:59:36     INFO -  66 INFO java.lang.reflect.Method.invoke(Method.java:511)
09:59:36     INFO -  67 INFO android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
09:59:36     INFO -  68 INFO android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
09:59:36     INFO -  69 INFO android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
09:59:36     INFO -  70 INFO org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:144)
09:59:36     INFO -  71 INFO junit.framework.TestCase.runBare(TestCase.java:134)
09:59:36     INFO -  72 INFO junit.framework.TestResult$1.protect(TestResult.java:115)
09:59:36     INFO -  73 INFO junit.framework.TestResult.runProtected(TestResult.java:133)
09:59:36     INFO -  74 INFO junit.framework.TestResult.run(TestResult.java:118)
09:59:36     INFO -  75 INFO junit.framework.TestCase.run(TestCase.java:124)
09:59:36     INFO -  76 INFO android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:190)
09:59:36     INFO -  77 INFO android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:175)
09:59:36     INFO -  78 INFO android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:555)
09:59:36     INFO -  79 INFO android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1661)
09:59:36     INFO -  80 INFO Thread[Picasso-Idle,5,main]
09:59:36     INFO -  81 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  82 INFO java.lang.Thread.parkFor(Thread.java:1231)
09:59:36     INFO -  83 INFO sun.misc.Unsafe.park(Unsafe.java:323)
09:59:36     INFO -  84 INFO java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
09:59:36     INFO -  85 INFO java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
09:59:36     INFO -  86 INFO java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
09:59:36     INFO -  87 INFO java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
09:59:36     INFO -  88 INFO java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
09:59:36     INFO -  89 INFO java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
09:59:36     INFO -  90 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  91 INFO com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
09:59:36     INFO -  92 INFO Thread[JDWP,5,system]
09:59:36     INFO -  93 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  94 INFO Thread[Gecko,5,main]
09:59:36     INFO -  95 INFO org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method)
09:59:36     INFO -  96 INFO org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:353)
09:59:36     INFO -  97 INFO org.mozilla.gecko.GeckoThread.run(GeckoThread.java:178)
09:59:36     INFO -  98 INFO Thread[ModernAsyncTask #2,5,main]
09:59:36     INFO -  99 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  100 INFO java.lang.Thread.parkFor(Thread.java:1231)
09:59:36     INFO -  101 INFO sun.misc.Unsafe.park(Unsafe.java:323)
09:59:36     INFO -  102 INFO java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
09:59:36     INFO -  103 INFO java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
09:59:36     INFO -  104 INFO java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
09:59:36     INFO -  105 INFO java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
09:59:36     INFO -  106 INFO java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
09:59:36     INFO -  107 INFO java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
09:59:36     INFO -  108 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  109 INFO Thread[Timer-0,5,main]
09:59:36     INFO -  110 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  111 INFO java.lang.Object.wait(Object.java:401)
09:59:36     INFO -  112 INFO java.util.Timer$TimerImpl.run(Timer.java:238)
09:59:36     INFO -  113 INFO Thread[actionMode,5,main]
09:59:36     INFO -  114 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  115 INFO java.lang.Object.wait(Object.java:364)
09:59:36     INFO -  116 INFO java.util.Timer$TimerImpl.run(Timer.java:214)
09:59:36     INFO -  117 INFO Thread[GC,5,system]
09:59:36     INFO -  118 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  119 INFO Thread[Binder_1,5,main]
09:59:36     INFO -  120 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  121 INFO Thread[Picasso-Stats,5,main]
09:59:36     INFO -  122 INFO android.os.MessageQueue.nativePollOnce(Native Method)
09:59:36     INFO -  123 INFO android.os.MessageQueue.next(MessageQueue.java:125)
09:59:36     INFO -  124 INFO android.os.Looper.loop(Looper.java:124)
09:59:36     INFO -  125 INFO android.os.HandlerThread.run(HandlerThread.java:60)
09:59:36     INFO -  126 INFO Thread[Binder_2,5,main]
09:59:36     INFO -  127 INFO dalvik.system.NativeStart.run(Native Method)
09:59:36     INFO -  128 INFO Thread[FinalizerWatchdogDaemon,5,system]
09:59:36     INFO -  129 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  130 INFO java.lang.Object.wait(Object.java:364)
09:59:36     INFO -  131 INFO java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
09:59:36     INFO -  132 INFO java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
09:59:36     INFO -  133 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  134 INFO Thread[GeckoBackgroundThread,5,main]
09:59:36     INFO -  135 INFO android.os.MessageQueue.nativePollOnce(Native Method)
09:59:36     INFO -  136 INFO android.os.MessageQueue.next(MessageQueue.java:125)
09:59:36     INFO -  137 INFO android.os.Looper.loop(Looper.java:124)
09:59:36     INFO -  138 INFO org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:32)
09:59:36     INFO -  139 INFO Thread[ModernAsyncTask #1,5,main]
09:59:36     INFO -  140 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  141 INFO java.lang.Thread.parkFor(Thread.java:1231)
09:59:36     INFO -  142 INFO sun.misc.Unsafe.park(Unsafe.java:323)
09:59:36     INFO -  143 INFO java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
09:59:36     INFO -  144 INFO java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
09:59:36     INFO -  145 INFO java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
09:59:36     INFO -  146 INFO java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
09:59:36     INFO -  147 INFO java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
09:59:36     INFO -  148 INFO java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
09:59:36     INFO -  149 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  150 INFO Thread[GeckoANRReporter,5,main]
09:59:36     INFO -  151 INFO android.os.MessageQueue.nativePollOnce(Native Method)
09:59:36     INFO -  152 INFO android.os.MessageQueue.next(MessageQueue.java:125)
09:59:36     INFO -  153 INFO android.os.Looper.loop(Looper.java:124)
09:59:36     INFO -  154 INFO org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:95)
09:59:36     INFO -  155 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  156 INFO Thread[Picasso-refQueue,5,main]
09:59:36     INFO -  157 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  158 INFO java.lang.Object.wait(Object.java:401)
09:59:36     INFO -  159 INFO java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
09:59:36     INFO -  160 INFO java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
09:59:36     INFO -  161 INFO com.squareup.picasso.Picasso$CleanupThread.run(Picasso.java:352)
09:59:36     INFO -  162 INFO Thread[pool-1-thread-1,5,main]
09:59:36     INFO -  163 INFO java.lang.Object.wait(Native Method)
09:59:36     INFO -  164 INFO java.lang.Thread.parkFor(Thread.java:1231)
09:59:36     INFO -  165 INFO sun.misc.Unsafe.park(Unsafe.java:323)
09:59:36     INFO -  166 INFO java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
09:59:36     INFO -  167 INFO java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
09:59:36     INFO -  168 INFO java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
09:59:36     INFO -  169 INFO java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
09:59:36     INFO -  170 INFO java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
09:59:36     INFO -  171 INFO java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
09:59:36     INFO -  172 INFO java.lang.Thread.run(Thread.java:856)
09:59:36     INFO -  173 INFO TEST-UNEXPECTED-FAIL | testAndroidLog | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
09:59:36     INFO -  TEST-INFO | expected PASS
09:59:36     INFO -  174 INFO EventExpecter: no longer listening for Robocop:JS
09:59:36     INFO -  175 INFO Unregistered listener for Robocop:JS
09:59:36     INFO -  176 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAndroidLog | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
09:59:36     INFO -  177 INFO TEST-UNEXPECTED-FAIL | testAndroidLog | Exception caught - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAndroidLog | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
09:59:36     INFO -  TEST-INFO | expected PASS
09:59:36     INFO -  178 INFO TEST-OK | testAndroidLog | took 148434ms
09:59:36     INFO -  179 INFO TEST-START | Shutdown
09:59:36     INFO -  180 INFO Passed: 1
09:59:36  WARNING -  181 INFO Failed: 2
09:59:36  WARNING -  One or more unittests failed.
09:59:36     INFO -  182 INFO Todo: 0
09:59:36     INFO -  183 INFO SimpleTest FINISHED
testAndroidLog was re-written as mochitest-chrome test_android_log.html.
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1184186
You need to log in before you can comment on or make changes to this bug.