Some of the test crashes reported in bug 1167565 are more specifically this one: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=68298425&lineNumber=1901 task 2017-01-12T06:14:00.388997Z] 06:14:00 WARNING - PROCESS-CRASH | testAndroidCastDeviceProvider | java-exception java.lang.IllegalStateException: Already registered AndroidCastDevice:Start under a different type at org.mozilla.gecko.EventDispatcher.checkNotRegisteredElsewhere(EventDispatcher.java:149) [task 2017-01-12T06:14:00.389292Z] 06:14:00 INFO - 0 ERROR runApp() exited with code 1 [task 2017-01-12T06:14:00.861072Z] 06:14:00 WARNING - PROCESS-CRASH | Automation Error: Missing end of test marker (process crashed?) [task 2017-01-12T06:14:01.211504Z] 06:14:01 INFO - 01-11 22:13:32.400 D/GeckoBrowserApp( 2042): BrowserApp.onTabChanged: 0: THUMBNAIL [task 2017-01-12T06:14:01.211925Z] 06:14:01 INFO - 01-11 22:13:32.490 W/GeckoEventDispatcher( 2042): No listeners for Content:DOMContentLoaded in dispatchToThreads [task 2017-01-12T06:14:01.212313Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): [JavaScript Error: "TypeError: invalid 'instanceof' operand Ci.amIWebInstallInfo" {file: "chrome://browser/content/browser.js" line: 5163}] [task 2017-01-12T06:14:01.212983Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): observe@chrome://browser/content/browser.js:5163:1 [task 2017-01-12T06:14:01.213423Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): startup/BrowserApp_delayedStartup/<@chrome://browser/content/browser.js:517:23 [task 2017-01-12T06:14:01.213792Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): maybeInit@resource://gre/modules/DelayedInit.jsm:105:9 [task 2017-01-12T06:14:01.213877Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): onIdle@resource://gre/modules/DelayedInit.jsm:77:9 [task 2017-01-12T06:14:01.214496Z] 06:14:01 INFO - 01-11 22:13:33.800 E/GeckoConsole( 2042): onIdle/<@resource://gre/modules/DelayedInit.jsm:90:38 [task 2017-01-12T06:14:01.214576Z] 06:14:01 INFO - 01-11 22:13:34.460 I/GeckoConsole( 2042): PAC file installed from data: URI [task 2017-01-12T06:14:01.215202Z] 06:14:01 INFO - 01-11 22:13:34.590 I/GeckoBrowserApp( 2042): Found tag [task 2017-01-12T06:14:01.215278Z] 06:14:01 INFO - 01-11 22:13:34.731 D/AndroidRuntime( 2042): Shutting down VM [task 2017-01-12T06:14:01.215359Z] 06:14:01 INFO - 01-11 22:13:34.731 W/dalvikvm( 2042): threadid=1: thread exiting with uncaught exception (group=0x414c8700) [task 2017-01-12T06:14:01.215987Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): >>> REPORTING UNCAUGHT EXCEPTION FROM THREAD 1 ("main") [task 2017-01-12T06:14:01.216085Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): java.lang.IllegalStateException: Already registered AndroidCastDevice:Start under a different type [task 2017-01-12T06:14:01.216465Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at org.mozilla.gecko.EventDispatcher.checkNotRegisteredElsewhere(EventDispatcher.java:149) [task 2017-01-12T06:14:01.216816Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at org.mozilla.gecko.EventDispatcher.registerGeckoThreadListener(EventDispatcher.java:176) [task 2017-01-12T06:14:01.217205Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at org.mozilla.gecko.MediaPlayerManager.onCreate(MediaPlayerManager.java:82) [task 2017-01-12T06:14:01.217306Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.Fragment.performCreate(Unknown Source) [task 2017-01-12T06:14:01.217406Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.FragmentManagerImpl.moveToState(Unknown Source) [task 2017-01-12T06:14:01.217948Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.FragmentManagerImpl.moveToState(Unknown Source) [task 2017-01-12T06:14:01.218289Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.BackStackRecord.run(Unknown Source) [task 2017-01-12T06:14:01.218617Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.FragmentManagerImpl.execPendingActions(Unknown Source) [task 2017-01-12T06:14:01.218729Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.support.v4.app.FragmentManagerImpl$1.run(Unknown Source) [task 2017-01-12T06:14:01.219311Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.os.Handler.handleCallback(Handler.java:730) [task 2017-01-12T06:14:01.219419Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.os.Handler.dispatchMessage(Handler.java:92) [task 2017-01-12T06:14:01.219941Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.os.Looper.loop(Looper.java:137) [task 2017-01-12T06:14:01.220088Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at android.app.ActivityThread.main(ActivityThread.java:5103) [task 2017-01-12T06:14:01.220715Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at java.lang.reflect.Method.invokeNative(Native Method) [task 2017-01-12T06:14:01.220817Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at java.lang.reflect.Method.invoke(Method.java:525) [task 2017-01-12T06:14:01.221545Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) [task 2017-01-12T06:14:01.221970Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) [task 2017-01-12T06:14:01.222364Z] 06:14:01 INFO - 01-11 22:13:34.750 E/GeckoCrashHandler( 2042): at dalvik.system.NativeStart.main(Native Method) [task 2017-01-12T06:14:01.222463Z] 06:14:01 INFO - 01-11 22:13:34.870 W/google-breakpad( 2042): ExceptionHandler::GenerateDump cloned child

Does that always happen?

(In reply to Tommy Kuo [:KuoE0] from comment #1) > Does that always happen? No, not at all. Most runs certainly pass. Looking over recent failures of this test reported in bug1167565, I see 2 with this signature: https://public-artifacts.taskcluster.net/Xvu4vpq3TGKVOn42QxgCWw/0/public/logs/live_backing.log https://public-artifacts.taskcluster.net/PFUpUaZvRjeC3KK5koybDQ/0/public/logs/live_backing.log and 1 that is different: https://public-artifacts.taskcluster.net/ZjvpMwZDS_OplIPZP7wBOQ/0/public/logs/live_backing.log I also noticed that most passing runs of testAndroidCastDeviceProvider have an ANR report. The way this works is the robocop test harness runs a test, then checks /data/anr for reports; if found, it dumps the report in the test log and deletes the original file. The presence of an ANR report is not considered an error - the test passes, the job stays green - but it is unusual and may be cause for concern. https://public-artifacts.taskcluster.net/bOEHR_AASaCb0whH--4yTA/0/public/logs/live_backing.log [task 2017-01-17T16:38:30.464397Z] 16:38:30 INFO - TEST-OK | testAndroidCastDeviceProvider | took 33772ms [task 2017-01-17T16:38:30.464435Z] 16:38:30 INFO - TEST-START | Shutdown [task 2017-01-17T16:38:30.464459Z] 16:38:30 INFO - Passed: 55 [task 2017-01-17T16:38:30.464476Z] 16:38:30 INFO - Failed: 0 [task 2017-01-17T16:38:30.464497Z] 16:38:30 INFO - Todo: 0 [task 2017-01-17T16:38:30.464515Z] 16:38:30 INFO - SimpleTest FINISHED [task 2017-01-17T16:38:51.589347Z] 16:38:51 INFO - INFO | automation.py | Application ran for: 0:03:59.783920 [task 2017-01-17T16:38:51.589651Z] 16:38:51 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpkkj0Ilpidlog [task 2017-01-17T16:38:51.925845Z] 16:38:51 INFO - Contents of /data/anr/traces.txt: [task 2017-01-17T16:38:51.926069Z] 16:38:51 INFO - ----- pid 1887 at 2017-01-17 08:35:51 ----- [task 2017-01-17T16:38:51.926272Z] 16:38:51 INFO - Cmd line: org.mozilla.fennec [task 2017-01-17T16:38:51.926503Z] 16:38:51 INFO - JNI: CheckJNI is on; workarounds are off; pins=0; globals=259 [task 2017-01-17T16:38:51.926683Z] 16:38:51 INFO - DALVIK THREADS: [task 2017-01-17T16:38:51.926893Z] 16:38:51 INFO - (mutexes: tll=0 tsl=0 tscl=0 ghl=0) [task 2017-01-17T16:38:51.927097Z] 16:38:51 INFO - "Thread-101" prio=5 tid=1 VMWAIT