Intermittent testInputConnection | GeckoEventExpecter - blockForEvent timeout: Robocop:JS

RESOLVED FIXED in Firefox 52

Status

()

defect
P3
normal
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: KWierso, Assigned: jchen)

Tracking

({intermittent-failure})

Trunk
Firefox 54
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox51 wontfix, firefox52 fixed, firefox-esr52 fixed, firefox53 fixed, firefox54 fixed)

Details

Attachments

(1 attachment)

Regression from bug 1255586?
Flags: needinfo?(nchen)
I'm npot (In reply to Geoff Brown [:gbrown] from comment #3)
> Regression from bug 1255586?

Not sure. The line that actually caused the timeout is from before bug 1255586?.
Flags: needinfo?(nchen)
http://archive.mozilla.org/pub/mobile/tinderbox-builds/fx-team-android-api-15/1470493460/fx-team_ubuntu64_vm_armv7_mobile_test-robocop-4-bm121-tests1-linux64-build36.txt.gz

08:22:48     INFO -  SimpleTest START
08:22:48     INFO -  TEST-START | testInputConnection
08:22:48     INFO -  TEST-PASS | testInputConnection | Robocop tests need the test device screen to be powered on. -
08:22:48     INFO -  TEST-PASS | testInputConnection | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
08:22:48     INFO -  EventExpecter: no longer listening for Gecko:Ready
08:22:48     INFO -  TEST-PASS | testInputConnection | url is not null - /robocop/robocop_input.html should not equal null
08:22:48     INFO -  TEST-PASS | testInputConnection | url is not null - /robocop/robocop_input.html should not equal null
08:22:48     INFO -  TEST-PASS | testInputConnection | The toolbar is not in the editing state -
08:22:48     INFO -  TEST-PASS | testInputConnection | Waiting for Toolbar to enter editing mode. -
08:22:48     INFO -  TEST-PASS | testInputConnection | Waiting for UrlEditText to be input method target. -
08:22:48     INFO -  TEST-PASS | testInputConnection | url is not null - http://mochi.test:8888/tests/robocop/robocop_input.html should not equal null
08:22:48     INFO -  TEST-PASS | testInputConnection | The toolbar is in the editing state -
08:22:48     INFO -  TEST-PASS | testInputConnection | The UrlEditText is the input method target -
08:22:48     INFO -  TEST-PASS | testInputConnection | The toolbar is in the editing state -
08:22:48     INFO -  TEST-PASS | testInputConnection | initiatingAction is not null - org.mozilla.gecko.tests.components.ToolbarComponent$2@41a21340 should not equal null
08:22:48     INFO -  ToolbarTitleTextChangeVerifier: stored title, "".
08:22:48     INFO -  EventExpecter: no longer listening for DOMContentLoaded
08:22:48     INFO -  EventExpecter: no longer listening for DOMTitleChanged
08:22:48     INFO -  ToolbarTitleTextChangeVerifier: state changed to title, "mochi.test:8888/tests/robocop/robocop_input.html".
08:22:48     INFO -  ToolbarTitleTextChangeVerifier: was satisfied.
08:22:48     INFO -  TEST-PASS | testInputConnection | Waiting for Toolbar to exit editing mode. -
08:22:48     INFO -  TEST-PASS | testInputConnection | The url argument is not null - /robocop/robocop_input.html should not equal null
08:22:48     INFO -  TEST-PASS | testInputConnection | url is not null - /robocop/robocop_input.html should not equal null
08:22:48     INFO -  TEST-PASS | testInputConnection | The toolbar is not in the editing state -
08:22:48     INFO -  TEST-PASS | testInputConnection | The Toolbar title is mochi.test:8888/tests/robocop/robocop_input.html - mochi.test:8888/tests/robocop/robocop_input.html should equal mochi.test:8888/tests/robocop/robocop_input.html
08:23:00     INFO -  Dumping ALL the threads!
08:23:00     INFO -  Thread[GeckoANRReporter,5,main]
08:23:00     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
08:23:00     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
08:23:00     INFO -  android.os.Looper.loop(Looper.java:124)
08:23:00     INFO -  org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:101)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[Binder_2,5,main]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[Thread-93,5,main]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[Binder_1,5,main]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[GC,5,system]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[Picasso-Stats,5,main]
08:23:00     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
08:23:00     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
08:23:00     INFO -  android.os.Looper.loop(Looper.java:124)
08:23:00     INFO -  android.os.HandlerThread.run(HandlerThread.java:61)
08:23:00     INFO -  Thread[FinalizerWatchdogDaemon,5,system]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:364)
08:23:00     INFO -  java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230)
08:23:00     INFO -  java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[pool-1-thread-1,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[JDWP,5,system]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[Instr: org.mozilla.gecko.FennecInstrumentationTestRunner,5,main]
08:23:00     INFO -  dalvik.system.VMStack.getThreadStackTrace(Native Method)
08:23:00     INFO -  java.lang.Thread.getStackTrace(Thread.java:579)
08:23:00     INFO -  java.lang.Thread.getAllStackTraces(Thread.java:521)
08:23:00     INFO -  org.mozilla.gecko.FennecNativeDriver.logAllStackTraces(FennecNativeDriver.java:317)
08:23:00     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:96)
08:23:00     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:81)
08:23:00     INFO -  org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:145)
08:23:00     INFO -  org.mozilla.gecko.tests.helpers.JavascriptBridge.processPendingMessage(JavascriptBridge.java:178)
08:23:00     INFO -  org.mozilla.gecko.tests.helpers.JavascriptBridge.ensureJavaBridgeLoaded(JavascriptBridge.java:222)
08:23:00     INFO -  org.mozilla.gecko.tests.helpers.JavascriptBridge.sendMessage(JavascriptBridge.java:227)
08:23:00     INFO -  org.mozilla.gecko.tests.helpers.JavascriptBridge.syncCall(JavascriptBridge.java:129)
08:23:00     INFO -  org.mozilla.gecko.tests.testInputConnection.testInputConnection(testInputConnection.java:41)
08:23:00     INFO -  java.lang.reflect.Method.invokeNative(Native Method)
08:23:00     INFO -  java.lang.reflect.Method.invoke(Method.java:525)
08:23:00     INFO -  android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
08:23:00     INFO -  android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
08:23:00     INFO -  android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
08:23:00     INFO -  org.mozilla.gecko.tests.BaseRobocopTest.runTest(BaseRobocopTest.java:189)
08:23:00     INFO -  junit.framework.TestCase.runBare(TestCase.java:134)
08:23:00     INFO -  junit.framework.TestResult$1.protect(TestResult.java:115)
08:23:00     INFO -  junit.framework.TestResult.runProtected(TestResult.java:133)
08:23:00     INFO -  junit.framework.TestResult.run(TestResult.java:118)
08:23:00     INFO -  junit.framework.TestCase.run(TestCase.java:124)
08:23:00     INFO -  android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
08:23:00     INFO -  android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
08:23:00     INFO -  android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
08:23:00     INFO -  org.mozilla.gecko.FennecInstrumentationTestRunner.onStart(FennecInstrumentationTestRunner.java:64)
08:23:00     INFO -  android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
08:23:00     INFO -  Thread[Compiler,5,system]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[Picasso-refQueue,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:401)
08:23:00     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
08:23:00     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
08:23:00     INFO -  com.squareup.picasso.Picasso$CleanupThread.run(Picasso.java:352)
08:23:00     INFO -  Thread[Binder_3,5,main]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[pool-2-thread-1,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[ReferenceQueueDaemon,5,system]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:364)
08:23:00     INFO -  java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[FinalizerDaemon,5,system]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:401)
08:23:00     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
08:23:00     INFO -  java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
08:23:00     INFO -  java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[ModernAsyncTask #11,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[Signal Catcher,5,system]
08:23:00     INFO -  dalvik.system.NativeStart.run(Native Method)
08:23:00     INFO -  Thread[ModernAsyncTask #13,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[ModernAsyncTask #21,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[Picasso-Idle,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
08:23:00     INFO -  Thread[actionMode,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:364)
08:23:00     INFO -  java.util.Timer$TimerImpl.run(Timer.java:214)
08:23:00     INFO -  Thread[Timer-0,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:364)
08:23:00     INFO -  java.util.Timer$TimerImpl.run(Timer.java:214)
08:23:00     INFO -  Thread[main,5,main]
08:23:00     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
08:23:00     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
08:23:00     INFO -  android.os.Looper.loop(Looper.java:124)
08:23:00     INFO -  android.app.ActivityThread.main(ActivityThread.java:5103)
08:23:00     INFO -  java.lang.reflect.Method.invokeNative(Native Method)
08:23:00     INFO -  java.lang.reflect.Method.invoke(Method.java:525)
08:23:00     INFO -  com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737)
08:23:00     INFO -  com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
08:23:00     INFO -  dalvik.system.NativeStart.main(Native Method)
08:23:00     INFO -  Thread[GeckoBackgroundThread,5,main]
08:23:00     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
08:23:00     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
08:23:00     INFO -  android.os.Looper.loop(Looper.java:124)
08:23:00     INFO -  org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:43)
08:23:00     INFO -  Thread[ModernAsyncTask #18,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[ModernAsyncTask #19,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[activityMonitorThread,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Object.wait(Object.java:401)
08:23:00     INFO -  android.app.Instrumentation$ActivityMonitor.waitForActivityWithTimeout(Instrumentation.java:550)
08:23:00     INFO -  com.robotium.solo.ActivityUtils$1.run(ActivityUtils.java:152)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  Thread[Gecko,5,main]
08:23:00     INFO -  org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method)
08:23:00     INFO -  org.mozilla.gecko.GeckoThread.run(GeckoThread.java:520)
08:23:00     INFO -  Thread[Picasso-Dispatcher,5,main]
08:23:00     INFO -  android.os.MessageQueue.nativePollOnce(Native Method)
08:23:00     INFO -  android.os.MessageQueue.next(MessageQueue.java:132)
08:23:00     INFO -  android.os.Looper.loop(Looper.java:124)
08:23:00     INFO -  android.os.HandlerThread.run(HandlerThread.java:61)
08:23:00     INFO -  Thread[Picasso-Idle,5,main]
08:23:00     INFO -  java.lang.Object.wait(Native Method)
08:23:00     INFO -  java.lang.Thread.parkFor(Thread.java:1205)
08:23:00     INFO -  sun.misc.Unsafe.park(Unsafe.java:325)
08:23:00     INFO -  java.util.concurrent.locks.LockSupport.park(LockSupport.java:159)
08:23:00     INFO -  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019)
08:23:00     INFO -  java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073)
08:23:00     INFO -  java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08:23:00     INFO -  java.lang.Thread.run(Thread.java:841)
08:23:00     INFO -  com.squareup.picasso.Utils$PicassoThread.run(Utils.java:294)
08:23:00  WARNING -  TEST-UNEXPECTED-FAIL | testInputConnection | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
08:23:12     INFO -  0 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testInputConnection | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
08:23:12     INFO -  	at junit.framework.Assert.fail(Assert.java:50)
08:23:12     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:128)
08:23:12     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:150)
08:23:12     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:97)
08:23:12     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEvent(FennecNativeActions.java:81)
08:23:12     INFO -  	at org.mozilla.gecko.FennecNativeActions$GeckoEventExpecter.blockForEventData(FennecNativeActions.java:145)
08:23:12     INFO -  	at org.mozilla.gecko.tests.helpers.JavascriptBridge.processPendingMessage(JavascriptBridge.java:178)
08:23:12     INFO -  	at org.mozilla.gecko.tests.helpers.JavascriptBridge.ensureJavaBridgeLoaded(JavascriptBridge.java:222)
08:23:12     INFO -  	at org.mozilla.gecko.tests.helpers.JavascriptBridge.sendMessage(JavascriptBridge.java:227)
08:23:12     INFO -  	at org.mozilla.gecko.tests.helpers.JavascriptBridge.syncCall(JavascriptBridge.java:129)
08:23:12     INFO -  	at org.mozilla.gecko.tests.testInputConnection.testInputConnection(testInputConnection.java:41)
08:23:12     INFO -  	at java.lang.reflect.Method.invokeNative(Native Method)
08:23:12     INFO -  	at java.lang.reflect.Method.invoke(Method.java:525)
08:23:12     INFO -  	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
08:23:12     INFO -  	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
08:23:12     INFO -  	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
08:23:12     INFO -  	at org.mozilla.gecko.tests.BaseRobocopTest.runTest(BaseRobocopTest.java:189)
08:23:12     INFO -  	at junit.framework.TestCase.runBare(TestCase.java:134)
08:23:12     INFO -  	at junit.framework.TestResult$1.protect(TestResult.java:115)
08:23:12     INFO -  	at junit.framework.TestResult.runProtected(TestResult.java:133)
08:23:12     INFO -  	at junit.framework.TestResult.run(TestResult.java:118)
08:23:12     INFO -  	at junit.framework.TestCase.run(TestCase.java:124)
08:23:12     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
08:23:12     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
08:23:12     INFO -  	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
08:23:12     INFO -  	at org.mozilla.gecko.FennecInstrumentationTestRunner.onStart(FennecInstrumentationTestRunner.java:64)
08:23:12     INFO -  	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
08:23:12  WARNING -  TEST-UNEXPECTED-FAIL | testInputConnection | Exception caught - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testInputConnection | GeckoEventExpecter - blockForEvent timeout: Robocop:JS
08:23:12     INFO -  EventExpecter: no longer listening for Robocop:JS
08:23:12     INFO -  TEST-OK | testInputConnection | took 331677ms
08:23:12     INFO -  TEST-START | Shutdown
08:23:12     INFO -  Passed: 17
08:23:12     INFO -  Failed: 2
08:23:12     INFO -  Todo: 0
08:23:12     INFO -  SimpleTest FINISHED

08:23:28     INFO -  08-06 08:19:57.805 I/Robocop ( 1281): {"message":"","time":1470496797757,"source":"robocop","status":"PASS","test":"testInputConnection","thread":null,"subtest":"The toolbar is not in the editing state","action":"test_status","pid":null}
08:23:28     INFO -  08-06 08:19:58.906 I/Robocop ( 1281): {"message":"mochi.test:8888\/tests\/robocop\/robocop_input.html should equal mochi.test:8888\/tests\/robocop\/robocop_input.html","time":1470496798874,"source":"robocop","status":"PASS","test":"testInputConnection","thread":null,"subtest":"The Toolbar title is mochi.test:8888\/tests\/robocop\/robocop_input.html","action":"test_status","pid":null}
08:23:28     INFO -  08-06 08:20:02.604 E/GeckoConsole( 1281): [JavaScript Error: "The Components object is deprecated. It will soon be removed." {file: "http://mochi.test:8888/tests/robocop/robocop_head.js" line: 16}]
08:23:28     INFO -  08-06 08:20:04.064 E/GeckoConsole( 1281): [JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: " {file: "http://mochi.test:8888/tests/robocop/robocop_input.html" line: 21}]
08:23:28     INFO -  08-06 08:20:04.064 E/GeckoConsole( 1281): @http://mochi.test:8888/tests/robocop/robocop_input.html:21:7
08:23:28     INFO -  08-06 08:20:05.484 D/GeckoTabs( 1281): handleMessage: DOMContentLoaded
08:23:28     INFO -  08-06 08:20:05.504 D/GeckoToolbar( 1281): onTabChanged: LOADED
08:23:28     INFO -  08-06 08:20:05.514 D/GeckoBrowserApp( 1281): BrowserApp.onTabChanged: 0: LOADED
08:23:28     INFO -  08-06 08:20:07.316 D/GeckoTabs( 1281): handleMessage: Content:PageShow
08:23:28     INFO -  08-06 08:20:07.534 D/GeckoToolbar( 1281): onTabChanged: PAGE_SHOW
08:23:28     INFO -  08-06 08:20:07.534 D/GeckoBrowserApp( 1281): BrowserApp.onTabChanged: 0: PAGE_SHOW
08:23:28     INFO -  08-06 08:20:08.774 D/GeckoTabs( 1281): handleMessage: Content:StateChange
08:23:28     INFO -  08-06 08:20:09.404 D/GeckoToolbar( 1281): onTabChanged: STOP
08:23:28     INFO -  08-06 08:20:09.404 I/GeckoToolbarDisplayLayout( 1281): zerdatime 1087557 - Throbber stop
08:23:28     INFO -  08-06 08:20:09.545 D/GeckoBrowserApp( 1281): BrowserApp.onTabChanged: 0: STOP
Many failed runs, including comment 28, contain:

JavaScript Error: "NS_ERROR_ILLEGAL_VALUE: " {file: "http://mochi.test:8888/tests/robocop/robocop_input.html" line: 21}]

which does not appear in logcats for successful runs.

That line seems to be:

      designMode.contentDocument.designMode = "on";

If we cannot set designMode, I suppose the rest of the test is not going to run well.

:jchen -- Thoughts?
Flags: needinfo?(nchen)
Sounds right, but not sure why setting designMode would fail some of the time.
Flags: needinfo?(nchen)
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
I was running into this in some local runs. If the first set designMode call
fails, schedule another call for a later time so it hopefully succeeds.
Attachment #8838794 - Flags: review?(gbrown)
Attachment #8838794 - Flags: review?(gbrown) → review+
Pushed by nchen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/bb5d3a227ee8
Try setting designMode again; r=gbrown
https://hg.mozilla.org/mozilla-central/rev/bb5d3a227ee8
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 54
Assignee: nobody → nchen
You need to log in before you can comment on or make changes to this bug.