Recently we have started getting a lot of "application ran for longer than maximum time" bugs for Android reftests. That happens when the reftest harness runs for longer than 90 minutes. Current non-failing run times for many chunks are in the 60 - 90 minute range. I don't see a sudden increase in number of tests or run time over the last several days...likely just a gradual increase in tests, or decrease in test performance.

Comment on attachment 8923570 [details] [diff] [review] run android opt plain reftests in 24 chunks Review of attachment 8923570 [details] [diff] [review]: ----------------------------------------------------------------- I was worried this was going to be 48 -> 71 or something like that, glad this is just 12 -> 24

Pushed by gbrown@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/75d5058f5a47 Increase number of test chunks for Android 4.3 opt plain reftests; r=jmaher

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=160201561&repo=autoland&lineNumber=4723 [task 2018-02-03T03:22:34.033Z] 03:22:34 INFO - REFTEST TEST-START | http://10.0.2.2:8888/tests/layout/reftests/scrolling/fractional-scroll-area.html?top=0.4&outerBottom=100.4&innerBottom=200.4&scrollBefore=999 == http://10.0.2.2:8888/tests/layout/reftests/scrolling/fractional-scroll-area.html?top=0&outerBottom=100&innerBottom=200&scrollBefore=999 [task 2018-02-03T03:22:34.034Z] 03:22:34 INFO - REFTEST TEST-LOAD | http://10.0.2.2:8888/tests/layout/reftests/scrolling/fractional-scroll-area.html?top=0.4&outerBottom=100.4&innerBottom=200.4&scrollBefore=999 | 608 / 624 (97%) [task 2018-02-03T03:22:34.754Z] 03:22:34 INFO - Browser unexpectedly found running. Killing... [task 2018-02-03T03:22:34.756Z] 03:22:34 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-02-03T03:22:34.778Z] 03:22:34 INFO - XScreenSaver state: Disabled [task 2018-02-03T03:22:34.779Z] 03:22:34 INFO - User input has been idle for 5600 seconds [task 2018-02-03T03:22:35.119Z] 03:22:35 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-02-03T03:22:38.920Z] 03:22:38 INFO - org.mozilla.fennec_aurora still alive after SIGABRT: waiting... [task 2018-02-03T03:22:44.045Z] 03:22:44 WARNING - TEST-UNEXPECTED-FAIL | http://10.0.2.2:8888/tests/layout/reftests/scrolling/fractional-scroll-area.html?top=0.4&outerBottom=100.4&innerBottom=200.4&scrollBefore=999 == http://10.0.2.2:8888/tests/layout/reftests/scrolling/fractional-scroll-area.html?top=0&outerBottom=100&innerBottom=200&scrollBefore=999 | application ran for longer than allowed maximum time [task 2018-02-03T03:22:44.046Z] 03:22:44 INFO - INFO | automation.py | Application ran for: 1:30:35.051965 [task 2018-02-03T03:22:44.046Z] 03:22:44 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpVZa5UUpidlog [task 2018-02-03T03:22:44.183Z] 03:22:44 INFO - Contents of /data/anr/traces.txt: [task 2018-02-03T03:22:44.184Z] 03:22:44 INFO - ----- pid 787 at 2018-02-02 19:22:35 ----- [task 2018-02-03T03:22:44.185Z] 03:22:44 INFO - Cmd line: org.mozilla.fennec_aurora [task 2018-02-03T03:22:44.185Z] 03:22:44 INFO - JNI: CheckJNI is on; workarounds are off; pins=0; globals=289 [task 2018-02-03T03:22:44.186Z] 03:22:44 INFO - DALVIK THREADS: [task 2018-02-03T03:22:44.186Z] 03:22:44 INFO - (mutexes: tll=0 tsl=0 tscl=0 ghl=0) [task 2018-02-03T03:22:44.187Z] 03:22:44 INFO - "main" prio=5 tid=1 NATIVE [task 2018-02-03T03:22:44.187Z] 03:22:44 INFO - | group="main" sCount=1 dsCount=0 obj=0x414c9578 self=0x2a00d090 [task 2018-02-03T03:22:44.188Z] 03:22:44 INFO - | sysTid=787 nice=0 sched=0/0 cgrp=apps handle=1073811452 [task 2018-02-03T03:22:44.188Z] 03:22:44 INFO - | state=S schedstat=( 403541270562 184435070349 445909 ) utm=23593 stm=16761 core=0 [task 2018-02-03T03:22:44.189Z] 03:22:44 INFO - #00 pc 0001c5a4 /system/lib/libc.so (__futex_syscall3+8) [task 2018-02-03T03:22:44.189Z] 03:22:44 INFO - #01 pc 0000e688 /system/lib/libc.so (__pthread_cond_timedwait_relative+48) [task 2018-02-03T03:22:44.190Z] 03:22:44 INFO - #02 pc 0000e6e8 /system/lib/libc.so (__pthread_cond_timedwait+64) [task 2018-02-03T03:22:44.190Z] 03:22:44 INFO - #03 pc 00052e97 /system/lib/libdvm.so [task 2018-02-03T03:22:44.191Z] 03:22:44 INFO - #04 pc 00053461 /system/lib/libdvm.so (dvmChangeStatus(Thread*, ThreadStatus)+30) [task 2018-02-03T03:22:44.191Z] 03:22:44 INFO - #05 pc 00048d29 /system/lib/libdvm.so [task 2018-02-03T03:22:44.192Z] 03:22:44 INFO - #06 pc 00039afd /system/lib/libdvm.so [task 2018-02-03T03:22:44.192Z] 03:22:44 INFO - #07 pc 0004b7a9 /system/lib/libandroid_runtime.so (android::AndroidRuntime::getJNIEnv()+16) [task 2018-02-03T03:22:44.192Z] 03:22:44 INFO - #08 pc 0005eed5 /system/lib/libandroid_runtime.so (android::NativeDisplayEventReceiver::dispatchVsync(long long, int, unsigned int)+20) [task 2018-02-03T03:22:44.193Z] 03:22:44 INFO - #09 pc 0005f0b9 /system/lib/libandroid_runtime.so (android::NativeDisplayEventReceiver::handleEvent(int, int, void*)+80) [task 2018-02-03T03:22:44.193Z] 03:22:44 INFO - #10 pc 00015129 /system/lib/libutils.so (android::Looper::pollInner(int)+468) [task 2018-02-03T03:22:44.193Z] 03:22:44 INFO - #11 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-02-03T03:22:44.194Z] 03:22:44 INFO - #12 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-02-03T03:22:44.194Z] 03:22:44 INFO - #13 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-02-03T03:22:44.194Z] 03:22:44 INFO - #14 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-02-03T03:22:44.195Z] 03:22:44 INFO - #15 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-02-03T03:22:44.195Z] 03:22:44 INFO - #16 pc 00027060 /system/lib/libdvm.so [task 2018-02-03T03:22:44.196Z] 03:22:44 INFO - #17 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-02-03T03:22:44.196Z] 03:22:44 INFO - #18 pc 0005ff7b /system/lib/libdvm.so (dvmInvokeMethod(Object*, Method const*, ArrayObject*, ArrayObject*, ClassObject*, bool)+350) [task 2018-02-03T03:22:44.197Z] 03:22:44 INFO - #19 pc 00067a9f /system/lib/libdvm.so [task 2018-02-03T03:22:44.197Z] 03:22:44 INFO - #20 pc 00027060 /system/lib/libdvm.so [task 2018-02-03T03:22:44.197Z] 03:22:44 INFO - #21 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-02-03T03:22:44.198Z] 03:22:44 INFO - #22 pc 0005fcbd /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292) [task 2018-02-03T03:22:44.198Z] 03:22:44 INFO - #23 pc 000499ab /system/lib/libdvm.so [task 2018-02-03T03:22:44.198Z] 03:22:44 INFO - #24 pc 0003cb3d /system/lib/libdvm.so [task 2018-02-03T03:22:44.199Z] 03:22:44 INFO - #25 pc 0004b68f /system/lib/libandroid_runtime.so [task 2018-02-03T03:22:44.199Z] 03:22:44 INFO - #26 pc 0004c30f /system/lib/libandroid_runtime.so (android::AndroidRuntime::start(char const*, char const*)+378) [task 2018-02-03T03:22:44.199Z] 03:22:44 INFO - #27 pc 0000105b /system/bin/app_process [task 2018-02-03T03:22:44.200Z] 03:22:44 INFO - #28 pc 0000db4f /system/lib/libc.so (__libc_init+50) [task 2018-02-03T03:22:44.200Z] 03:22:44 INFO - #29 pc 00000d7c /system/bin/app_process [task 2018-02-03T03:22:44.200Z] 03:22:44 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-02-03T03:22:44.201Z] 03:22:44 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-02-03T03:22:44.201Z] 03:22:44 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-02-03T03:22:44.202Z] 03:22:44 INFO - at android.app.ActivityThread.main(ActivityThread.java:5103) [task 2018-02-03T03:22:44.203Z] 03:22:44 INFO - at java.lang.reflect.Method.invokeNative(Native Method) [task 2018-02-03T03:22:44.203Z] 03:22:44 INFO - at java.lang.reflect.Method.invoke(Method.java:525) [task 2018-02-03T03:22:44.204Z] 03:22:44 INFO - at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) [task 2018-02-03T03:22:44.204Z] 03:22:44 INFO - at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) [task 2018-02-03T03:22:44.205Z] 03:22:44 INFO - at dalvik.system.NativeStart.main(Native Method) [task 2018-02-03T03:22:44.205Z] 03:22:44 INFO - "Thread-78" prio=5 tid=29 NATIVE

I'm addressing the new failures in bug 1433163.