Intermittent testWebChannel | GeckoEventExpecter - blockForEvent timeout: Robocop:JS

RESOLVED DUPLICATE of bug 1190643

Status

()

Firefox for Android
General
RESOLVED DUPLICATE of bug 1190643
3 years ago
3 years ago

People

(Reporter: RyanVM, Unassigned)

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(Reporter)

Description

3 years ago
First test in the chunk. Coincidence?

17:10:10     INFO -  SimpleTest START
17:10:10     INFO -  TEST-START | testWebChannel
17:10:10     INFO -  TEST-PASS | testWebChannel | Robocop tests need the test device screen to be powered on. -
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
17:10:10     INFO -  EventExpecter: no longer listening for Gecko:Ready
17:10:10     INFO -  Registered listener for Robocop:JS
17:10:10     INFO -  Loading JavaScript test from http://mochi.test:8888/tests/robocop/robocop_javascript.html?slug=1438646779745&path=testWebChannel.js
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 1 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS
17:10:10     INFO -  (xpcshell/head.js) | test 1 pending
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS
17:10:10     INFO -  (xpcshell/head.js) | test 2 pending
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"message":"\nTEST-INFO | testWebChannel.js | Starting test","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS
17:10:10     INFO -  testWebChannel.js | Starting test
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"message":"\nTEST-INFO | testWebChannel.js | Running: WebChannel generic message\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS
17:10:10     INFO -  testWebChannel.js | Running: WebChannel generic message
17:10:10     INFO -  TEST-PASS | testWebChannel | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 finished\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS
17:10:10     INFO -  (xpcshell/head.js) | test 2 finished
17:10:10     INFO -  Dumping ALL the threads!
17:10:10     INFO -  Thread[Instr: org.mozilla.gecko.FennecInstrumentationTestRunner,5,main]
17:10:10     INFO -  dalvik.system.VMStack.getThreadStackTrace(Native Method)
17:10:10     INFO -  java.lang.Thread.getStackTrace(Thread.java:579)
17:10:10     INFO -  java.lang.Thread.getAllStackTraces(Thread.java:521)
17:10:10     INFO -  org.mozilla.gecko.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:317)
17:10:10     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:95)
17:10:10     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:80)
17:10:10     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:144)
17:10:10     INFO -  org.mozilla.gecko.tests.JavascriptTest.doTestJavascript(JavascriptTest.java:54)
17:10:10     INFO -  org.mozilla.gecko.tests.JavascriptTest.testJavascript(JavascriptTest.java:33)
17:10:10     INFO -  java.lang.reflect.Method.invokeNative(Native Method)
17:10:10     INFO -  java.lang.reflect.Method.invoke(Method.java:525)
17:10:10     INFO -  android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
17:10:10     INFO -  android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
17:10:10     INFO -  android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
17:10:10     INFO -  org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:133)
17:10:10     INFO -  junit.framework.TestCase.runBare(TestCase.java:134)
17:10:10     INFO -  junit.framework.TestResult$1.protect(TestResult.java:115)
17:10:10     INFO -  junit.framework.TestResult.runProtected(TestResult.java:133)
17:10:10     INFO -  junit.framework.TestResult.run(TestResult.java:118)
17:10:10     INFO -  junit.framework.TestCase.run(TestCase.java:124)
17:10:10     INFO -  android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
17:10:10     INFO -  android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
17:10:10     INFO -  android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
17:10:10     INFO -  android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
17:10:10     INFO -  Thread[Compiler,5,system]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[actionMode,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:364)
17:10:10     INFO -  java.util.Timer$TimerImpl.run(Timer.java:214)
17:10:10     INFO -  Thread[Picasso-Idle,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
17:10:10     INFO -  Thread[Binder_1,5,main]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[FinalizerWatchdogDaemon,5,system]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:364)
17:10:10     INFO -  java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
17:10:10     INFO -  java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[ModernAsyncTask #1,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[FinalizerDaemon,5,system]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:401)
17:10:10     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
17:10:10     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
17:10:10     INFO -  java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[Thread-73,5,main]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[Picasso-Stats,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  android.os.HandlerThread.run(HandlerThread.java:61)
17:10:10     INFO -  Thread[JDWP,5,system]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[ReferenceQueueDaemon,5,system]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:364)
17:10:10     INFO -  java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[pool-3-thread-1,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[ModernAsyncTask #2,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[Picasso-Dispatcher,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  android.os.HandlerThread.run(HandlerThread.java:61)
17:10:10     INFO -  Thread[Timer-0,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:401)
17:10:10     INFO -  java.util.Timer$TimerImpl.run(Timer.java:238)
17:10:10     INFO -  Thread[Binder_2,5,main]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[GC,5,system]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[NsdManager,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  android.os.HandlerThread.run(HandlerThread.java:61)
17:10:10     INFO -  Thread[Picasso-refQueue,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Object.wait(Object.java:401)
17:10:10     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
17:10:10     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
17:10:10     INFO -  com.squareup.picasso.Picasso$CleanupThread.run(Picasso.java:352)
17:10:10     INFO -  Thread[main,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  android.app.ActivityThread.main(ActivityThread.java:5103)
17:10:10     INFO -  java.lang.reflect.Method.invokeNative(Native Method)
17:10:10     INFO -  java.lang.reflect.Method.invoke(Method.java:525)
17:10:10     INFO -  com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737)
17:10:10     INFO -  com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
17:10:10     INFO -  dalvik.system.NativeStart.main(Native Method)
17:10:10     INFO -  Thread[pool-1-thread-1,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[Gecko,5,main]
17:10:10     INFO -  org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method)
17:10:10     INFO -  org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:387)
17:10:10     INFO -  org.mozilla.gecko.GeckoThread.run(GeckoThread.java:188)
17:10:10     INFO -  Thread[pool-2-thread-1,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[GeckoANRReporter,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:101)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  Thread[Signal Catcher,5,system]
17:10:10     INFO -  dalvik.system.NativeStart.run(Native Method)
17:10:10     INFO -  Thread[GeckoBackgroundThread,5,main]
17:10:10     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
17:10:10     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
17:10:10     INFO -  android.os.Looper.loop(Looper.java:124)
17:10:10     INFO -  org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:43)
17:10:10     INFO -  Thread[Picasso-Idle,5,main]
17:10:10     INFO -  java.lang.Object.wait(Native Method)
17:10:10     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
17:10:10     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
17:10:10     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
17:10:10     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
17:10:10     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
17:10:10     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
17:10:10     INFO -  java.lang.Thread.run(Thread.java:841)
17:10:10     INFO -  com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
17:10:10  WARNING -  TEST-UNEXPECTED-FAIL | testWebChannel | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
17:10:10     INFO -  EventExpecter: no longer listening for Robocop:JS
17:10:10     INFO -  Unregistered listener for Robocop:JS
17:10:10     INFO -  0 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testWebChannel | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
17:10:10     INFO -  	at junit.framework.Assert.fail(Assert.java:50)
17:10:10     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:128)
17:10:10     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:150)
17:10:10     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:96)
17:10:10     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:80)
17:10:10     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:144)
17:10:10     INFO -  	at org.mozilla.gecko.tests.JavascriptTest.doTestJavascript(JavascriptTest.java:54)
17:10:10     INFO -  	at org.mozilla.gecko.tests.JavascriptTest.testJavascript(JavascriptTest.java:33)
17:10:10     INFO -  	at java.lang.reflect.Method.invokeNative(Native Method)
17:10:10     INFO -  	at java.lang.reflect.Method.invoke(Method.java:525)
17:10:10     INFO -  	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
17:10:10     INFO -  	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
17:10:10     INFO -  	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
17:10:10     INFO -  	at org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:133)
17:10:10     INFO -  	at junit.framework.TestCase.runBare(TestCase.java:134)
17:10:10     INFO -  	at junit.framework.TestResult$1.protect(TestResult.java:115)
17:10:10     INFO -  	at junit.framework.TestResult.runProtected(TestResult.java:133)
17:10:10     INFO -  	at junit.framework.TestResult.run(TestResult.java:118)
17:10:10     INFO -  	at junit.framework.TestCase.run(TestCase.java:124)
17:10:10     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
17:10:10     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
17:10:10     INFO -  	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
17:10:10     INFO -  	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
17:10:10  WARNING -  TEST-UNEXPECTED-FAIL | testWebChannel | Exception caught - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testWebChannel | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
17:10:10     INFO -  TEST-OK | testWebChannel | took 271129ms
17:10:10     INFO -  TEST-START | Shutdown
17:10:10     INFO -  Passed: 7
17:10:10     INFO -  Failed: 2
17:10:10     INFO -  Todo: 0
17:10:10     INFO -  SimpleTest FINISHED
Comment hidden (Treeherder Robot)
17:10:26     INFO -  08-03 17:06:50.408 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: START
17:10:26     INFO -  08-03 17:06:51.191 D/Robocop (  790): handleMessage called for: Robocop:JS; expecting: Robocop:JS
17:10:26     INFO -  08-03 17:06:51.288 I/Robocop (  790): {"message":"Robocop:JS should equal Robocop:JS","time":1438646811256,"source":"robocop","status":"PASS","test":"testWebChannel","thread":null,"subtest":"Given message occurred for registered event: {\"message\":\"\\nTEST-INFO | (xpcshell\\\/head.js) | test 2 finished\\n\",\"innerType\":\"progress\",\"type\":\"Robocop:JS\"}","action":"test_status","pid":null}
17:10:26     INFO -  08-03 17:06:51.288 D/Robocop (  790): received event Robocop:JS
17:10:26     INFO -  08-03 17:06:51.328 D/Robocop (  790): unblocked on expecter for Robocop:JS
17:10:26     INFO -  08-03 17:06:51.408 I/Robocop (  790): {"action":"log","message":"(xpcshell\/head.js) | test 2 finished","time":1438646811332,"pid":null,"level":"info","source":"robocop","thread":null}
17:10:26     INFO -  08-03 17:06:55.658 D/GeckoTabs(  790): handleMessage: Content:LocationChange
17:10:26     INFO -  08-03 17:06:55.779 D/GeckoTabs(  790): handleMessage: Content:SecurityChange
17:10:26     INFO -  08-03 17:06:56.021 W/GeckoGlobalHistory(  790): Rebuilding visited link set...
17:10:26     INFO -  08-03 17:06:56.149 D/GeckoToolbar(  790): onTabChanged: LOCATION_CHANGE
17:10:26     INFO -  08-03 17:06:56.149 D/GeckoToolbarDisplayLayout(  790): updateFavicon(null)
17:10:26     INFO -  08-03 17:06:56.159 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: LOCATION_CHANGE
17:10:26     INFO -  08-03 17:06:56.159 D/GeckoToolbar(  790): onTabChanged: SECURITY_CHANGE
17:10:26     INFO -  08-03 17:06:56.169 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: SECURITY_CHANGE
17:10:26     INFO -  08-03 17:06:56.863 W/BroadcastQueue(  285): Timeout of broadcast BroadcastRecord{419e2d58 u-1 android.intent.action.TIME_TICK} - receiver=android.os.BinderProxy@4193d388, started 60006ms ago
17:10:26     INFO -  08-03 17:06:56.863 W/BroadcastQueue(  285): Receiver during timeout: BroadcastFilter{418ffa28 u0 ReceiverList{41905840 348 com.android.systemui/10025/u0 remote:4193d388}}
17:10:26     INFO -  08-03 17:06:57.448 E/BluetoothAdapter(  451): Bluetooth binder is null
17:10:26     INFO -  08-03 17:07:00.118 D/GeckoMemoryMonitor(  790): onTrimMemory() notification received with level 15
17:10:26     INFO -  08-03 17:07:00.149 D/GeckoMemoryMonitor(  790): increasing memory pressure to 4
17:10:26     INFO -  08-03 17:07:00.748 D/GeckoTabs(  790): handleMessage: Tab:ViewportMetadata
17:10:26     INFO -  08-03 17:07:01.318 D/GeckoToolbar(  790): onTabChanged: VIEWPORT_CHANGE
17:10:26     INFO -  08-03 17:07:01.318 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 0: VIEWPORT_CHANGE
17:10:26     INFO -  08-03 17:07:04.089 E/        (  421): RS Message thread exiting.
17:10:26     INFO -  08-03 17:07:04.159 E/RenderScript(  421): rsAssert failed: !mTypes.size(), in frameworks/rs/rsType.cpp at 59
17:10:26     INFO -  08-03 17:07:04.568 E/RenderScript(  421): rsAssert failed: !mElements.size(), in frameworks/rs/rsElement.cpp at 375
17:10:26     INFO -  08-03 17:07:05.059 V/SmsReceiverService(  610): onStart: #1 mResultCode: -1 = Activity.RESULT_OK
17:10:26     INFO -  08-03 17:07:05.689 D/GeckoTabs(  790): handleMessage: DOMTitleChanged
17:10:26     INFO -  08-03 17:07:05.689 D/GeckoToolbar(  790): onTabChanged: TITLE
17:10:26     INFO -  08-03 17:07:05.889 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: TITLE
17:10:26     INFO -  08-03 17:07:07.011 D/GeckoTabs(  790): handleMessage: Tab:ViewportMetadata
17:10:26     INFO -  08-03 17:07:07.051 D/GeckoToolbar(  790): onTabChanged: VIEWPORT_CHANGE
17:10:26     INFO -  08-03 17:07:07.051 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: VIEWPORT_CHANGE
17:10:26     INFO -  08-03 17:07:08.539 D/GeckoTabs(  790): handleMessage: DOMContentLoaded
17:10:26     INFO -  08-03 17:07:08.539 D/GeckoToolbar(  790): onTabChanged: LOADED
17:10:26     INFO -  08-03 17:07:08.549 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: LOADED
17:10:26     INFO -  08-03 17:07:08.989 I/ActivityManager(  285): Start proc com.svox.pico for broadcast com.svox.pico/.VoiceDataInstallerReceiver: pid=870 uid=10011 gids={50011, 1015, 1028}
17:10:26     INFO -  08-03 17:07:12.328 D/GeckoTabs(  790): handleMessage: Content:PageShow
17:10:26     INFO -  08-03 17:07:12.399 D/GeckoToolbar(  790): onTabChanged: PAGE_SHOW
17:10:26     INFO -  08-03 17:07:12.399 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: PAGE_SHOW
17:10:26     INFO -  08-03 17:07:15.498 D/GeckoTabs(  790): handleMessage: Content:StateChange
17:10:26     INFO -  08-03 17:07:15.498 D/GeckoToolbar(  790): onTabChanged: STOP
17:10:26     INFO -  08-03 17:07:15.518 I/GeckoToolbarDisplayLayout(  790): zerdatime 472878 - Throbber stop
17:10:26     INFO -  08-03 17:07:15.598 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: STOP
17:10:26     INFO -  08-03 17:07:16.009 D/GeckoThumbnailHelper(  790): Using new thumbnail size: 242544 (width 326 - height 186)
17:10:26     INFO -  08-03 17:07:16.019 D/GeckoThumbnailHelper(  790): Sending thumbnail event: 326, 186
17:10:26     INFO -  08-03 17:07:17.231 I/Choreographer(  790): Skipped 44 frames!  The application may be doing too much work on its main thread.
17:10:26     INFO -  08-03 17:07:17.969 I/ActivityManager(  285): Start proc com.android.quicksearchbox for broadcast com.android.quicksearchbox/.CorporaUpdateReceiver: pid=883 uid=10027 gids={50027, 3003, 1028}
17:10:26     INFO -  08-03 17:07:19.890 E/LoadFaviconTask(  790): Error reading favicon
17:10:26     INFO -  08-03 17:07:20.169 E/LoadFaviconTask(  790): Error reading favicon
17:10:26     INFO -  08-03 17:07:20.618 D/GeckoToolbar(  790): onTabChanged: FAVICON
17:10:26     INFO -  08-03 17:07:20.618 D/GeckoToolbarDisplayLayout(  790): updateFavicon(android.graphics.Bitmap@41787680)
17:10:26     INFO -  08-03 17:07:20.639 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: FAVICON
17:10:26     INFO -  08-03 17:07:23.438 E/GeckoConsole(  790): [JavaScript Error: "Failed to execute callback:TypeError: dump is not a function" {file: "resource://gre/modules/WebChannel.jsm" line: 312}]
17:10:26     INFO -  08-03 17:07:25.759 I/ActivityManager(  285): Start proc com.android.keychain for broadcast com.android.keychain/.KeyChainBroadcastReceiver: pid=899 uid=1000 gids={41000, 1015, 1028, 3002, 3001, 3003}
17:10:26     INFO -  08-03 17:07:26.369 E/GeckoConsole(  790): [JavaScript Error: "1438646846365	Toolkit.Telemetry	ERROR	TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - Invalid date stored." {file: "resource://gre/modules/Log.jsm" line: 749}]
17:10:26     INFO -  08-03 17:07:26.468 W/ContextImpl(  899): Calling a method in the system process without a qualified user: android.app.ContextImpl.startService:1385 android.content.ContextWrapper.startService:473 android.content.ContextWrapper.startService:473 com.android.keychain.KeyChainBroadcastReceiver.onReceive:12 android.app.ActivityThread.handleReceiver:2424
17:10:26     INFO -  08-03 17:07:27.569 I/GeckoHealth(  790): fennec :: HealthReportBroadcastService :: Registering HealthReportUploadService.
17:10:26     INFO -  08-03 17:07:27.599 I/GeckoHealth(  790): fennec :: BackgroundService :: Setting inexact repeating alarm for interval 3600000
17:10:26     INFO -  08-03 17:07:27.989 I/GeckoBrowserApp(  790): Found tag
17:10:26     INFO -  08-03 17:07:28.909 I/dalvikvm(  790): Could not find method android.app.ActivityManager.isLowRamDevice, referenced from method android.support.v7.media.MediaRouter$GlobalMediaRouter.<init>
17:10:26     INFO -  08-03 17:07:28.909 W/dalvikvm(  790): VFY: unable to resolve virtual method 95: Landroid/app/ActivityManager;.isLowRamDevice ()Z
17:10:26     INFO -  08-03 17:07:29.318 I/MediaRouter(  790): Found default route: MediaRouter.RouteInfo{ uniqueId=android/.support.v7.media.SystemMediaRouteProvider:DEFAULT_ROUTE, name=Phone, description=null, enabled=true, connecting=false, canDisconnect=false, playbackType=0, playbackStream=3, volumeHandling=1, volume=11, volumeMax=15, presentationDisplayId=-1, extras=null, settingsIntent=null, providerPackageName=android }
17:10:26     INFO -  08-03 17:07:29.378 I/Choreographer(  790): Skipped 32 frames!  The application may be doing too much work on its main thread.
17:10:26     INFO -  08-03 17:07:35.578 I/GeckoConsole(  790): 1438646855582	Toolkit.GMP	WARN	GMPInstallManager.parseResponseXML got node name: html, expected: updates
17:10:26     INFO -  08-03 17:07:35.609 E/GeckoConsole(  790): [JavaScript Error: "1438646855603	Toolkit.GMP	ERROR	GMPInstallManager.simpleCheckAndInstall Could not check for addons: {"target":{},"message":"got node name: html, expected: updates"}" {file: "resource://gre/modules/Log.jsm" line: 749}]
17:10:26     INFO -  08-03 17:07:37.109 D/GeckoThumbnailHelper(  790): handleThumbnailData: 242544
17:10:26     INFO -  08-03 17:07:37.590 D/GeckoToolbar(  790): onTabChanged: THUMBNAIL
17:10:26     INFO -  08-03 17:07:37.590 D/GeckoBrowserApp(  790): BrowserApp.onTabChanged: 1: THUMBNAIL
17:10:26     INFO -  08-03 17:09:37.929 D/GeckoIdleService(  790): Get idle time: time since reset 150486 msec
17:10:26     INFO -  08-03 17:09:37.929 D/GeckoIdleService(  790): Idle timer callback: current idle time 150486 msec
17:10:26     INFO -  08-03 17:09:37.929 D/GeckoIdleService(  790): next timeout 29508 msec from now
17:10:26     INFO -  08-03 17:09:37.929 D/GeckoIdleService(  790): SetTimerExpiryIfBefore: next timeout 29506 msec from now
17:10:26     INFO -  08-03 17:09:37.938 D/GeckoIdleService(  790): reset timer expiry to 29510 msec from now
17:10:26     INFO -  08-03 17:09:51.539 E/Robocop (  790): Dumping ALL the threads!


Notice:
 - memory pressure
 - "dump is not a function"

Reminds me of bug 1167565.
Comment hidden (Treeherder Robot)

Updated

3 years ago
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1190643
You need to log in before you can comment on or make changes to this bug.