Closed Bug 1412953 Opened 4 years ago Closed 3 years ago

Android 4.3 opt plain reftests need more chunks

Categories

(Firefox Build System :: Task Configuration, task)

task
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED
mozilla58

People

(Reporter: gbrown, Assigned: gbrown)

References

(Blocks 1 open bug)

Details

Attachments

(1 file)

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.
Duplicate of this bug: 1410093
Duplicate of this bug: 1412721
Duplicate of this bug: 1412704
Duplicate of this bug: 1412735
Duplicate of this bug: 1412871
Duplicate of this bug: 1412941
Blocks: 1411358
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
Attachment #8923570 - Flags: review?(jmaher) → review+
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
https://hg.mozilla.org/mozilla-central/rev/75d5058f5a47
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
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
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
I'm addressing the new failures in bug 1433163.
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → FIXED
See Also: → 1433163
Product: TaskCluster → Firefox Build System
You need to log in before you can comment on or make changes to this bug.