Closed Bug 1465721 Opened 7 years ago Closed 7 years ago

Intermittent TEST-UNEXPECTED-FAIL | remoteautomation.py | application timed out after 670 seconds withno output

Categories

(Testing :: Reftest, defect, P5)

Product:
Testing
Component:
Reftest
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1416125

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

References

Details

(Keywords: intermittent-failure)

Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=180024212&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/TddbTWYOTYKGVghLdBoMeA/runs/0/artifacts/public/logs/live_backing.log https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/TddbTWYOTYKGVghLdBoMeA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 [task 2018-05-24T15:32:53.195Z] 15:32:53 INFO - launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_PROCESS_LOG=/tmp/tmpwim_kzpidlog --es env8 NO_EM_RESTART=1 --es args '-no-remote -profile /sdcard/tests/reftest/profile/' --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env2 R_LOG_VERBOSE=1 --es env1 XPCOM_DEBUG_BREAK=stack --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_CRASHREPORTER_NO_REPORT=1 --es env6 R_LOG_DESTINATION=stderr --es env5 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env4 MOZ_IN_AUTOMATION=1 --es env10 R_LOG_LEVEL=6 [task 2018-05-24T15:33:03.226Z] 15:33:03 INFO - INFO | automation.py | Application pid: 774 [task 2018-05-24T15:34:54.217Z] 15:34:54 INFO - REFTEST INFO | Reading manifest http://10.0.2.2:8888/../jsreftest/tests/jstests.list [task 2018-05-24T15:35:04.740Z] 15:35:04 INFO - REFTEST INFO | Dumping JSON representation of sandbox [task 2018-05-24T15:35:04.741Z] 15:35:04 INFO - REFTEST INFO | {"isDebugBuild":true,"xulRuntime":{"widgetToolkit":"android","OS":"Android","XPCOMABI":"arm-eabi-gcc3"},"smallScreen":false,"d2d":false,"dwrite":false,"gpuProcess":false,"azureCairo":false,"azureSkia":true,"skiaContent":true,"azureSkiaGL":1,"contentSameGfxBackendAsCanvas":true,"layersGPUAccelerated":true,"d3d11":false,"d3d9":false,"layersOpenGL":true,"webrender":false,"layersOMTC":true,"advancedLayers":false,"layerChecksEnabled":true,"retainedDisplayList":false,"Android":true,"cocoaWidget":false,"gtkWidget":false,"qtWidget":false,"winWidget":false,"transparentScrollbars":false,"AndroidVersion":18,"AddressSanitizer":false,"webrtc":true,"retainedDisplayLists":false,"compareRetainedDisplayLists":false,"stylo":true,"skiaPdf":false,"release_or_beta":false,"http":{"userAgent":"Mozilla/5.0 (Android 4.3.1; Mobile; rv:62.0) Gecko/62.0 Firefox/62.0","appName":"Mozilla","appVersion":"5.0","platform":"Android 4.3.1","oscpu":"Linux armv7l","misc":"rv:62.0"},"haveTestPlugin":false,"windowsDefaultTheme":false,"nativeThemePref":false,"gpuProcessForceEnabled":false,"prefs":{},"browserIsRemote":false,"asyncPan":true,"usesRepeatResampling":false,"verify":false} [task 2018-05-24T15:47:33.083Z] 15:47:33 INFO - Browser unexpectedly found running. Killing... [task 2018-05-24T15:47:33.083Z] 15:47:33 INFO - REFTEST TEST-INFO | started process screentopng [task 2018-05-24T15:47:33.430Z] 15:47:33 INFO - REFTEST TEST-INFO | screentopng: exit 0 [task 2018-05-24T15:47:48.377Z] 15:47:48 WARNING - TEST-UNEXPECTED-FAIL | remoteautomation.py | application timed out after 670 seconds withno output [task 2018-05-24T15:47:48.377Z] 15:47:48 INFO - INFO | automation.py | Application ran for: 0:14:55.386938 [task 2018-05-24T15:47:48.379Z] 15:47:48 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpwim_kzpidlog [task 2018-05-24T15:47:48.688Z] 15:47:48 INFO - Contents of /data/anr/traces.txt: [task 2018-05-24T15:47:48.688Z] 15:47:48 INFO - ----- pid 774 at 2018-05-24 08:47:33 ----- [task 2018-05-24T15:47:48.689Z] 15:47:48 INFO - Cmd line: org.mozilla.fennec_aurora [task 2018-05-24T15:47:48.689Z] 15:47:48 INFO - JNI: CheckJNI is on; workarounds are off; pins=0; globals=285 [task 2018-05-24T15:47:48.689Z] 15:47:48 INFO - DALVIK THREADS: [task 2018-05-24T15:47:48.689Z] 15:47:48 INFO - (mutexes: tll=0 tsl=0 tscl=0 ghl=0) [task 2018-05-24T15:47:48.689Z] 15:47:48 INFO - "main" prio=5 tid=1 NATIVE [task 2018-05-24T15:47:48.690Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x414c9578 self=0x2a00d090 [task 2018-05-24T15:47:48.690Z] 15:47:48 INFO - | sysTid=774 nice=0 sched=0/0 cgrp=apps handle=1073811452 [task 2018-05-24T15:47:48.690Z] 15:47:48 INFO - | state=S schedstat=( 69549213142 10555209745 55645 ) utm=4589 stm=2365 core=0 [task 2018-05-24T15:47:48.690Z] 15:47:48 INFO - #00 pc 0001c5a4 /system/lib/libc.so (__futex_syscall3+8) [task 2018-05-24T15:47:48.691Z] 15:47:48 INFO - #01 pc 0000e688 /system/lib/libc.so (__pthread_cond_timedwait_relative+48) [task 2018-05-24T15:47:48.691Z] 15:47:48 INFO - #02 pc 0000e6e8 /system/lib/libc.so (__pthread_cond_timedwait+64) [task 2018-05-24T15:47:48.691Z] 15:47:48 INFO - #03 pc 00052e97 /system/lib/libdvm.so [task 2018-05-24T15:47:48.691Z] 15:47:48 INFO - #04 pc 00053461 /system/lib/libdvm.so (dvmChangeStatus(Thread*, ThreadStatus)+30) [task 2018-05-24T15:47:48.692Z] 15:47:48 INFO - #05 pc 00048d29 /system/lib/libdvm.so [task 2018-05-24T15:47:48.692Z] 15:47:48 INFO - #06 pc 00039afd /system/lib/libdvm.so [task 2018-05-24T15:47:48.692Z] 15:47:48 INFO - #07 pc 0004b7a9 /system/lib/libandroid_runtime.so (android::AndroidRuntime::getJNIEnv()+16) [task 2018-05-24T15:47:48.693Z] 15:47:48 INFO - #08 pc 0005eed5 /system/lib/libandroid_runtime.so (android::NativeDisplayEventReceiver::dispatchVsync(long long, int, unsigned int)+20) [task 2018-05-24T15:47:48.693Z] 15:47:48 INFO - #09 pc 0005f0b9 /system/lib/libandroid_runtime.so (android::NativeDisplayEventReceiver::handleEvent(int, int, void*)+80) [task 2018-05-24T15:47:48.694Z] 15:47:48 INFO - #10 pc 00015129 /system/lib/libutils.so (android::Looper::pollInner(int)+468) [task 2018-05-24T15:47:48.694Z] 15:47:48 INFO - #11 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.695Z] 15:47:48 INFO - #12 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.695Z] 15:47:48 INFO - #13 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.695Z] 15:47:48 INFO - #14 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.696Z] 15:47:48 INFO - #15 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.696Z] 15:47:48 INFO - #16 pc 00000214 /dev/ashmem/dalvik-jit-code-cache (deleted) [task 2018-05-24T15:47:48.696Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.697Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.697Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.697Z] 15:47:48 INFO - at android.app.ActivityThread.main(ActivityThread.java:5103) [task 2018-05-24T15:47:48.698Z] 15:47:48 INFO - at java.lang.reflect.Method.invokeNative(Native Method) [task 2018-05-24T15:47:48.698Z] 15:47:48 INFO - at java.lang.reflect.Method.invoke(Method.java:525) [task 2018-05-24T15:47:48.698Z] 15:47:48 INFO - at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:737) [task 2018-05-24T15:47:48.699Z] 15:47:48 INFO - at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553) [task 2018-05-24T15:47:48.699Z] 15:47:48 INFO - at dalvik.system.NativeStart.main(Native Method) [task 2018-05-24T15:47:48.700Z] 15:47:48 INFO - "Thread-80" prio=5 tid=18 NATIVE [task 2018-05-24T15:47:48.700Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41e13710 self=0x2a0f16f8 [task 2018-05-24T15:47:48.700Z] 15:47:48 INFO - | sysTid=879 nice=0 sched=0/0 cgrp=apps handle=707153784 [task 2018-05-24T15:47:48.700Z] 15:47:48 INFO - | state=S schedstat=( 370007000 652142292 265 ) utm=35 stm=2 core=0 [task 2018-05-24T15:47:48.701Z] 15:47:48 INFO - #00 pc 0001c5a4 /system/lib/libc.so (__futex_syscall3+8) [task 2018-05-24T15:47:48.701Z] 15:47:48 INFO - #01 pc 0000e688 /system/lib/libc.so (__pthread_cond_timedwait_relative+48) [task 2018-05-24T15:47:48.702Z] 15:47:48 INFO - #02 pc 0000e6e8 /system/lib/libc.so (__pthread_cond_timedwait+64) [task 2018-05-24T15:47:48.702Z] 15:47:48 INFO - #03 pc 003f36af /data/data/org.mozilla.fennec_aurora/cache/libxul.so [task 2018-05-24T15:47:48.702Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.703Z] 15:47:48 INFO - "Picasso-refQueue" daemon prio=5 tid=30 WAIT [task 2018-05-24T15:47:48.703Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41e5da28 self=0x2a2b5328 [task 2018-05-24T15:47:48.704Z] 15:47:48 INFO - | sysTid=846 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707483512 [task 2018-05-24T15:47:48.704Z] 15:47:48 INFO - | state=S schedstat=( 908959 25582045 3 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.704Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.705Z] 15:47:48 INFO - - waiting on <0x41e5da18> (a java.lang.ref.ReferenceQueue) [task 2018-05-24T15:47:48.705Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:401) [task 2018-05-24T15:47:48.705Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102) [task 2018-05-24T15:47:48.706Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73) [task 2018-05-24T15:47:48.706Z] 15:47:48 INFO - at com.squareup.picasso.Picasso$CleanupThread.run(Picasso.java:352) [task 2018-05-24T15:47:48.706Z] 15:47:48 INFO - "Picasso-Dispatcher" prio=5 tid=29 NATIVE [task 2018-05-24T15:47:48.707Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41e5c8c8 self=0x2a3d68e0 [task 2018-05-24T15:47:48.707Z] 15:47:48 INFO - | sysTid=845 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=708668720 [task 2018-05-24T15:47:48.708Z] 15:47:48 INFO - | state=S schedstat=( 1805412 43113455 7 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.708Z] 15:47:48 INFO - #00 pc 0001c3dc /system/lib/libc.so (epoll_wait+12) [task 2018-05-24T15:47:48.708Z] 15:47:48 INFO - #01 pc 00014fb1 /system/lib/libutils.so (android::Looper::pollInner(int)+92) [task 2018-05-24T15:47:48.709Z] 15:47:48 INFO - #02 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.709Z] 15:47:48 INFO - #03 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.710Z] 15:47:48 INFO - #04 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.710Z] 15:47:48 INFO - #05 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.710Z] 15:47:48 INFO - #06 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.711Z] 15:47:48 INFO - #07 pc 00027060 /system/lib/libdvm.so [task 2018-05-24T15:47:48.711Z] 15:47:48 INFO - #08 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-05-24T15:47:48.712Z] 15:47:48 INFO - #09 pc 0005fcbd /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292) [task 2018-05-24T15:47:48.712Z] 15:47:48 INFO - #10 pc 0005fce7 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) [task 2018-05-24T15:47:48.712Z] 15:47:48 INFO - #11 pc 00054a6f /system/lib/libdvm.so [task 2018-05-24T15:47:48.713Z] 15:47:48 INFO - #12 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.713Z] 15:47:48 INFO - #13 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.713Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.714Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.714Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.714Z] 15:47:48 INFO - at android.os.HandlerThread.run(HandlerThread.java:61) [task 2018-05-24T15:47:48.715Z] 15:47:48 INFO - "Picasso-Stats" prio=5 tid=28 NATIVE [task 2018-05-24T15:47:48.715Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41e5ad28 self=0x2a305dc8 [task 2018-05-24T15:47:48.716Z] 15:47:48 INFO - | sysTid=844 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707523352 [task 2018-05-24T15:47:48.716Z] 15:47:48 INFO - | state=S schedstat=( 4146714 30610857 12 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.716Z] 15:47:48 INFO - #00 pc 0001c3dc /system/lib/libc.so (epoll_wait+12) [task 2018-05-24T15:47:48.717Z] 15:47:48 INFO - #01 pc 00014fb1 /system/lib/libutils.so (android::Looper::pollInner(int)+92) [task 2018-05-24T15:47:48.717Z] 15:47:48 INFO - #02 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.718Z] 15:47:48 INFO - #03 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.718Z] 15:47:48 INFO - #04 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.718Z] 15:47:48 INFO - #05 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.719Z] 15:47:48 INFO - #06 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.719Z] 15:47:48 INFO - #07 pc 00027060 /system/lib/libdvm.so [task 2018-05-24T15:47:48.720Z] 15:47:48 INFO - #08 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-05-24T15:47:48.720Z] 15:47:48 INFO - #09 pc 0005fcbd /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292) [task 2018-05-24T15:47:48.721Z] 15:47:48 INFO - #10 pc 0005fce7 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) [task 2018-05-24T15:47:48.721Z] 15:47:48 INFO - #11 pc 00054a6f /system/lib/libdvm.so [task 2018-05-24T15:47:48.721Z] 15:47:48 INFO - #12 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.722Z] 15:47:48 INFO - #13 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.722Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.723Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.723Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.723Z] 15:47:48 INFO - at android.os.HandlerThread.run(HandlerThread.java:61) [task 2018-05-24T15:47:48.724Z] 15:47:48 INFO - "AsyncTask #5" prio=5 tid=27 WAIT [task 2018-05-24T15:47:48.724Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41e004b0 self=0x2a2b4058 [task 2018-05-24T15:47:48.725Z] 15:47:48 INFO - | sysTid=832 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707478696 [task 2018-05-24T15:47:48.725Z] 15:47:48 INFO - | state=S schedstat=( 20852187 1431650764 33 ) utm=2 stm=0 core=0 [task 2018-05-24T15:47:48.725Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.726Z] 15:47:48 INFO - - waiting on <0x41e00608> (a java.lang.VMThread) held by tid=27 (AsyncTask #5) [task 2018-05-24T15:47:48.726Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.727Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.727Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.728Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.728Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.728Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.729Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.729Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.730Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.730Z] 15:47:48 INFO - "AsyncTask #4" prio=5 tid=26 WAIT [task 2018-05-24T15:47:48.730Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41dbbd20 self=0x2a3b3b38 [task 2018-05-24T15:47:48.731Z] 15:47:48 INFO - | sysTid=831 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=708562024 [task 2018-05-24T15:47:48.731Z] 15:47:48 INFO - | state=S schedstat=( 21523982 1848876417 33 ) utm=2 stm=0 core=0 [task 2018-05-24T15:47:48.731Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.732Z] 15:47:48 INFO - - waiting on <0x41dbbe40> (a java.lang.VMThread) held by tid=26 (AsyncTask #4) [task 2018-05-24T15:47:48.732Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.733Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.733Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.734Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.734Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.734Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.735Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.735Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.736Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.736Z] 15:47:48 INFO - "AsyncTask #3" prio=5 tid=25 WAIT [task 2018-05-24T15:47:48.737Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41b4e810 self=0x2a34fa78 [task 2018-05-24T15:47:48.737Z] 15:47:48 INFO - | sysTid=824 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=708116168 [task 2018-05-24T15:47:48.737Z] 15:47:48 INFO - | state=S schedstat=( 18028875 870484331 27 ) utm=0 stm=1 core=0 [task 2018-05-24T15:47:48.738Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.738Z] 15:47:48 INFO - - waiting on <0x41aa5cb8> (a java.lang.VMThread) held by tid=25 (AsyncTask #3) [task 2018-05-24T15:47:48.739Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.739Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.739Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.740Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.740Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.741Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.741Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.742Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.742Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.742Z] 15:47:48 INFO - "AsyncTask #2" prio=5 tid=24 WAIT [task 2018-05-24T15:47:48.743Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41b4c900 self=0x2a30f6c0 [task 2018-05-24T15:47:48.743Z] 15:47:48 INFO - | sysTid=823 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=708314552 [task 2018-05-24T15:47:48.744Z] 15:47:48 INFO - | state=S schedstat=( 19425599 853439325 26 ) utm=1 stm=0 core=0 [task 2018-05-24T15:47:48.744Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.744Z] 15:47:48 INFO - - waiting on <0x41b30808> (a java.lang.VMThread) held by tid=24 (AsyncTask #2) [task 2018-05-24T15:47:48.745Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.745Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.746Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.746Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.746Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.747Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.747Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.748Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.748Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.749Z] 15:47:48 INFO - "Picasso-refQueue" daemon prio=5 tid=23 WAIT [task 2018-05-24T15:47:48.749Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41ac1550 self=0x2a2e9360 [task 2018-05-24T15:47:48.749Z] 15:47:48 INFO - | sysTid=816 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707725512 [task 2018-05-24T15:47:48.750Z] 15:47:48 INFO - | state=S schedstat=( 916661 558108754 4 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.750Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.751Z] 15:47:48 INFO - - waiting on <0x41b91a50> (a java.lang.ref.ReferenceQueue) [task 2018-05-24T15:47:48.751Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:401) [task 2018-05-24T15:47:48.751Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102) [task 2018-05-24T15:47:48.752Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73) [task 2018-05-24T15:47:48.752Z] 15:47:48 INFO - at com.squareup.picasso.Picasso$CleanupThread.run(Picasso.java:352) [task 2018-05-24T15:47:48.753Z] 15:47:48 INFO - "Picasso-Dispatcher" prio=5 tid=22 NATIVE [task 2018-05-24T15:47:48.753Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41b62698 self=0x2a2e8540 [task 2018-05-24T15:47:48.753Z] 15:47:48 INFO - | sysTid=815 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707692944 [task 2018-05-24T15:47:48.754Z] 15:47:48 INFO - | state=S schedstat=( 2324465 685712393 9 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.754Z] 15:47:48 INFO - #00 pc 0001c3dc /system/lib/libc.so (epoll_wait+12) [task 2018-05-24T15:47:48.755Z] 15:47:48 INFO - #01 pc 00014fb1 /system/lib/libutils.so (android::Looper::pollInner(int)+92) [task 2018-05-24T15:47:48.755Z] 15:47:48 INFO - #02 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.756Z] 15:47:48 INFO - #03 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.756Z] 15:47:48 INFO - #04 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.757Z] 15:47:48 INFO - #05 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.757Z] 15:47:48 INFO - #06 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.757Z] 15:47:48 INFO - #07 pc 00027060 /system/lib/libdvm.so [task 2018-05-24T15:47:48.758Z] 15:47:48 INFO - #08 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-05-24T15:47:48.758Z] 15:47:48 INFO - #09 pc 0005fcbd /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292) [task 2018-05-24T15:47:48.759Z] 15:47:48 INFO - #10 pc 0005fce7 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) [task 2018-05-24T15:47:48.759Z] 15:47:48 INFO - #11 pc 00054a6f /system/lib/libdvm.so [task 2018-05-24T15:47:48.760Z] 15:47:48 INFO - #12 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.760Z] 15:47:48 INFO - #13 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.760Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.761Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.761Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.761Z] 15:47:48 INFO - at android.os.HandlerThread.run(HandlerThread.java:61) [task 2018-05-24T15:47:48.762Z] 15:47:48 INFO - "Picasso-Stats" prio=5 tid=21 NATIVE [task 2018-05-24T15:47:48.762Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41ae20b0 self=0x2a2e7ca0 [task 2018-05-24T15:47:48.763Z] 15:47:48 INFO - | sysTid=814 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707690736 [task 2018-05-24T15:47:48.763Z] 15:47:48 INFO - | state=S schedstat=( 1822656 572713277 7 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.763Z] 15:47:48 INFO - #00 pc 0001c3dc /system/lib/libc.so (epoll_wait+12) [task 2018-05-24T15:47:48.764Z] 15:47:48 INFO - #01 pc 00014fb1 /system/lib/libutils.so (android::Looper::pollInner(int)+92) [task 2018-05-24T15:47:48.764Z] 15:47:48 INFO - #02 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.765Z] 15:47:48 INFO - #03 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.765Z] 15:47:48 INFO - #04 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.765Z] 15:47:48 INFO - #05 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.766Z] 15:47:48 INFO - #06 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.766Z] 15:47:48 INFO - #07 pc 00027060 /system/lib/libdvm.so [task 2018-05-24T15:47:48.767Z] 15:47:48 INFO - #08 pc 0002b580 /system/lib/libdvm.so (dvmInterpret(Thread*, Method const*, JValue*)+184) [task 2018-05-24T15:47:48.767Z] 15:47:48 INFO - #09 pc 0005fcbd /system/lib/libdvm.so (dvmCallMethodV(Thread*, Method const*, Object*, bool, JValue*, std::__va_list)+292) [task 2018-05-24T15:47:48.768Z] 15:47:48 INFO - #10 pc 0005fce7 /system/lib/libdvm.so (dvmCallMethod(Thread*, Method const*, Object*, JValue*, ...)+20) [task 2018-05-24T15:47:48.768Z] 15:47:48 INFO - #11 pc 00054a6f /system/lib/libdvm.so [task 2018-05-24T15:47:48.768Z] 15:47:48 INFO - #12 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.769Z] 15:47:48 INFO - #13 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.769Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.770Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.770Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.771Z] 15:47:48 INFO - at android.os.HandlerThread.run(HandlerThread.java:61) [task 2018-05-24T15:47:48.771Z] 15:47:48 INFO - "AsyncTask #1" prio=5 tid=20 WAIT [task 2018-05-24T15:47:48.771Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41a9bc18 self=0x2a226270 [task 2018-05-24T15:47:48.772Z] 15:47:48 INFO - | sysTid=813 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707220592 [task 2018-05-24T15:47:48.772Z] 15:47:48 INFO - | state=S schedstat=( 280252333 15863043051 188 ) utm=25 stm=3 core=0 [task 2018-05-24T15:47:48.773Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.773Z] 15:47:48 INFO - - waiting on <0x41acd900> (a java.lang.VMThread) held by tid=20 (AsyncTask #1) [task 2018-05-24T15:47:48.773Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.774Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.774Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.775Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.775Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.775Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.776Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.776Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.777Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.777Z] 15:47:48 INFO - "ModernAsyncTask #3" prio=5 tid=19 WAIT [task 2018-05-24T15:47:48.778Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41ae45c0 self=0x2a2e7780 [task 2018-05-24T15:47:48.778Z] 15:47:48 INFO - | sysTid=811 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707687408 [task 2018-05-24T15:47:48.778Z] 15:47:48 INFO - | state=S schedstat=( 532429490 23912415832 329 ) utm=41 stm=12 core=0 [task 2018-05-24T15:47:48.779Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.779Z] 15:47:48 INFO - - waiting on <0x41ae4630> (a java.lang.VMThread) held by tid=19 (ModernAsyncTask #3) [task 2018-05-24T15:47:48.780Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.780Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.780Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.781Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.781Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.782Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.782Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.782Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.783Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.783Z] 15:47:48 INFO - "ModernAsyncTask #2" prio=5 tid=17 WAIT [task 2018-05-24T15:47:48.784Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41aa26d0 self=0x2a261408 [task 2018-05-24T15:47:48.784Z] 15:47:48 INFO - | sysTid=810 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=707685584 [task 2018-05-24T15:47:48.784Z] 15:47:48 INFO - | state=S schedstat=( 83300733 14075830775 169 ) utm=4 stm=4 core=0 [task 2018-05-24T15:47:48.785Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.785Z] 15:47:48 INFO - - waiting on <0x41ab4060> (a java.lang.VMThread) held by tid=17 (ModernAsyncTask #2) [task 2018-05-24T15:47:48.786Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.786Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.786Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.787Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.787Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.787Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.788Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.788Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.788Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.789Z] 15:47:48 INFO - "GeckoIconTask" prio=5 tid=16 WAIT [task 2018-05-24T15:47:48.789Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41b7da70 self=0x2a233bc0 [task 2018-05-24T15:47:48.789Z] 15:47:48 INFO - | sysTid=800 nice=0 sched=0/0 cgrp=apps handle=706953232 [task 2018-05-24T15:47:48.790Z] 15:47:48 INFO - | state=S schedstat=( 704638972 2575691225 806 ) utm=58 stm=12 core=0 [task 2018-05-24T15:47:48.790Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.790Z] 15:47:48 INFO - - waiting on <0x41b7db98> (a java.lang.VMThread) held by tid=16 (GeckoIconTask) [task 2018-05-24T15:47:48.791Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.791Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.791Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.792Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.792Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.792Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.792Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.793Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.793Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.793Z] 15:47:48 INFO - "ModernAsyncTask #1" prio=5 tid=15 WAIT [task 2018-05-24T15:47:48.794Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41b717e0 self=0x2a232310 [task 2018-05-24T15:47:48.794Z] 15:47:48 INFO - | sysTid=799 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=706948088 [task 2018-05-24T15:47:48.795Z] 15:47:48 INFO - | state=S schedstat=( 9516850 28440439 3 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.795Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.795Z] 15:47:48 INFO - - waiting on <0x41b719c8> (a java.lang.VMThread) held by tid=15 (ModernAsyncTask #1) [task 2018-05-24T15:47:48.796Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.796Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.796Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.797Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.797Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.797Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.798Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.798Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.799Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.799Z] 15:47:48 INFO - "actionMode" prio=5 tid=14 WAIT [task 2018-05-24T15:47:48.799Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41a57ca8 self=0x2a1e6b80 [task 2018-05-24T15:47:48.800Z] 15:47:48 INFO - | sysTid=797 nice=0 sched=0/0 cgrp=apps handle=706575744 [task 2018-05-24T15:47:48.800Z] 15:47:48 INFO - | state=S schedstat=( 718183 42567674 3 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.800Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.801Z] 15:47:48 INFO - - waiting on <0x41a57ca8> (a java.util.Timer$TimerImpl) [task 2018-05-24T15:47:48.801Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:364) [task 2018-05-24T15:47:48.801Z] 15:47:48 INFO - at java.util.Timer$TimerImpl.run(Timer.java:214) [task 2018-05-24T15:47:48.801Z] 15:47:48 INFO - "Gecko" prio=5 tid=13 NATIVE [task 2018-05-24T15:47:48.802Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41796be0 self=0x2a1e8430 [task 2018-05-24T15:47:48.802Z] 15:47:48 INFO - | sysTid=796 nice=0 sched=0/0 cgrp=apps handle=706641592 [task 2018-05-24T15:47:48.802Z] 15:47:48 INFO - | state=R schedstat=( 631505687002 233618975894 92510 ) utm=61120 stm=2030 core=0 [task 2018-05-24T15:47:48.803Z] 15:47:48 INFO - #00 pc 00802400 /data/data/org.mozilla.fennec_aurora/cache/libxul.so [task 2018-05-24T15:47:48.803Z] 15:47:48 INFO - #01 pc 00677097 /data/data/org.mozilla.fennec_aurora/cache/libxul.so [task 2018-05-24T15:47:48.803Z] 15:47:48 INFO - at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) [task 2018-05-24T15:47:48.803Z] 15:47:48 INFO - at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:498) [task 2018-05-24T15:47:48.804Z] 15:47:48 INFO - "pool-1-thread-1" prio=5 tid=12 WAIT [task 2018-05-24T15:47:48.804Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x41749d00 self=0x2a1e5c28 [task 2018-05-24T15:47:48.804Z] 15:47:48 INFO - | sysTid=794 nice=0 sched=0/0 cgrp=apps handle=706633848 [task 2018-05-24T15:47:48.804Z] 15:47:48 INFO - | state=S schedstat=( 157814287 150590213 113 ) utm=5 stm=10 core=0 [task 2018-05-24T15:47:48.805Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.805Z] 15:47:48 INFO - - waiting on <0x4174e7b0> (a java.lang.VMThread) held by tid=12 (pool-1-thread-1) [task 2018-05-24T15:47:48.805Z] 15:47:48 INFO - at java.lang.Thread.parkFor(Thread.java:1205) [task 2018-05-24T15:47:48.805Z] 15:47:48 INFO - at sun.misc.Unsafe.park(Unsafe.java:325) [task 2018-05-24T15:47:48.806Z] 15:47:48 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:159) [task 2018-05-24T15:47:48.806Z] 15:47:48 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2019) [task 2018-05-24T15:47:48.806Z] 15:47:48 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413) [task 2018-05-24T15:47:48.807Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1013) [task 2018-05-24T15:47:48.807Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1073) [task 2018-05-24T15:47:48.807Z] 15:47:48 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573) [task 2018-05-24T15:47:48.807Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.808Z] 15:47:48 INFO - "GeckoBackgroundThread" daemon prio=5 tid=11 NATIVE [task 2018-05-24T15:47:48.808Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x4177d438 self=0x2a04fdd8 [task 2018-05-24T15:47:48.808Z] 15:47:48 INFO - | sysTid=789 nice=0 sched=0/0 cgrp=apps handle=706631400 [task 2018-05-24T15:47:48.808Z] 15:47:48 INFO - | state=S schedstat=( 1477919940 4960191093 1222 ) utm=131 stm=16 core=0 [task 2018-05-24T15:47:48.809Z] 15:47:48 INFO - #00 pc 0001c3dc /system/lib/libc.so (epoll_wait+12) [task 2018-05-24T15:47:48.809Z] 15:47:48 INFO - #01 pc 00014fb1 /system/lib/libutils.so (android::Looper::pollInner(int)+92) [task 2018-05-24T15:47:48.809Z] 15:47:48 INFO - #02 pc 000151d5 /system/lib/libutils.so (android::Looper::pollOnce(int, int*, int*, void**)+92) [task 2018-05-24T15:47:48.809Z] 15:47:48 INFO - #03 pc 00067b69 /system/lib/libandroid_runtime.so (android::NativeMessageQueue::pollOnce(_JNIEnv*, int)+22) [task 2018-05-24T15:47:48.810Z] 15:47:48 INFO - #04 pc 0001dc4c /system/lib/libdvm.so (dvmPlatformInvoke+112) [task 2018-05-24T15:47:48.810Z] 15:47:48 INFO - #05 pc 0004dcab /system/lib/libdvm.so (dvmCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+394) [task 2018-05-24T15:47:48.810Z] 15:47:48 INFO - #06 pc 000385e1 /system/lib/libdvm.so (dvmCheckCallJNIMethod(unsigned int const*, JValue*, Method const*, Thread*)+8) [task 2018-05-24T15:47:48.811Z] 15:47:48 INFO - #07 pc 00000214 /dev/ashmem/dalvik-jit-code-cache (deleted) [task 2018-05-24T15:47:48.811Z] 15:47:48 INFO - at android.os.MessageQueue.nativePollOnce(Native Method) [task 2018-05-24T15:47:48.811Z] 15:47:48 INFO - at android.os.MessageQueue.next(MessageQueue.java:132) [task 2018-05-24T15:47:48.811Z] 15:47:48 INFO - at android.os.Looper.loop(Looper.java:124) [task 2018-05-24T15:47:48.812Z] 15:47:48 INFO - at org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:43) [task 2018-05-24T15:47:48.812Z] 15:47:48 INFO - "Binder_2" prio=5 tid=10 NATIVE [task 2018-05-24T15:47:48.812Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x4173fe20 self=0x2a04ebd0 [task 2018-05-24T15:47:48.813Z] 15:47:48 INFO - | sysTid=786 nice=0 sched=0/0 cgrp=apps handle=704965000 [task 2018-05-24T15:47:48.813Z] 15:47:48 INFO - | state=S schedstat=( 14119085 10983773 16 ) utm=1 stm=0 core=0 [task 2018-05-24T15:47:48.813Z] 15:47:48 INFO - #00 pc 0001b2d4 /system/lib/libc.so (__ioctl+8) [task 2018-05-24T15:47:48.814Z] 15:47:48 INFO - #01 pc 0002b94b /system/lib/libc.so (ioctl+14) [task 2018-05-24T15:47:48.814Z] 15:47:48 INFO - #02 pc 0001b539 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140) [task 2018-05-24T15:47:48.814Z] 15:47:48 INFO - #03 pc 0001bcd7 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154) [task 2018-05-24T15:47:48.815Z] 15:47:48 INFO - #04 pc 0001faa5 /system/lib/libbinder.so [task 2018-05-24T15:47:48.815Z] 15:47:48 INFO - #05 pc 00011a75 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216) [task 2018-05-24T15:47:48.815Z] 15:47:48 INFO - #06 pc 0004b629 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68) [task 2018-05-24T15:47:48.815Z] 15:47:48 INFO - #07 pc 00011569 /system/lib/libutils.so [task 2018-05-24T15:47:48.816Z] 15:47:48 INFO - #08 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.816Z] 15:47:48 INFO - #09 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.816Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.817Z] 15:47:48 INFO - "Binder_1" prio=5 tid=9 NATIVE [task 2018-05-24T15:47:48.817Z] 15:47:48 INFO - | group="main" sCount=1 dsCount=0 obj=0x4173fd30 self=0x2a04e188 [task 2018-05-24T15:47:48.817Z] 15:47:48 INFO - | sysTid=785 nice=0 sched=0/0 cgrp=apps handle=704800896 [task 2018-05-24T15:47:48.817Z] 15:47:48 INFO - | state=S schedstat=( 21424395 12465137 17 ) utm=2 stm=0 core=0 [task 2018-05-24T15:47:48.818Z] 15:47:48 INFO - #00 pc 0001b2d4 /system/lib/libc.so (__ioctl+8) [task 2018-05-24T15:47:48.818Z] 15:47:48 INFO - #01 pc 0002b94b /system/lib/libc.so (ioctl+14) [task 2018-05-24T15:47:48.818Z] 15:47:48 INFO - #02 pc 0001b539 /system/lib/libbinder.so (android::IPCThreadState::talkWithDriver(bool)+140) [task 2018-05-24T15:47:48.819Z] 15:47:48 INFO - #03 pc 0001bcd7 /system/lib/libbinder.so (android::IPCThreadState::joinThreadPool(bool)+154) [task 2018-05-24T15:47:48.819Z] 15:47:48 INFO - #04 pc 0001faa5 /system/lib/libbinder.so [task 2018-05-24T15:47:48.819Z] 15:47:48 INFO - #05 pc 00011a75 /system/lib/libutils.so (android::Thread::_threadLoop(void*)+216) [task 2018-05-24T15:47:48.820Z] 15:47:48 INFO - #06 pc 0004b629 /system/lib/libandroid_runtime.so (android::AndroidRuntime::javaThreadShell(void*)+68) [task 2018-05-24T15:47:48.820Z] 15:47:48 INFO - #07 pc 00011569 /system/lib/libutils.so [task 2018-05-24T15:47:48.820Z] 15:47:48 INFO - #08 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.821Z] 15:47:48 INFO - #09 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.821Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.821Z] 15:47:48 INFO - "FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT [task 2018-05-24T15:47:48.822Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173b508 self=0x2a025ed8 [task 2018-05-24T15:47:48.822Z] 15:47:48 INFO - | sysTid=784 nice=0 sched=0/0 cgrp=apps handle=704799528 [task 2018-05-24T15:47:48.823Z] 15:47:48 INFO - | state=S schedstat=( 1663117 35634451 9 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.823Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.823Z] 15:47:48 INFO - - waiting on <0x414d16d8> (a java.lang.Daemons$FinalizerWatchdogDaemon) [task 2018-05-24T15:47:48.824Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:364) [task 2018-05-24T15:47:48.824Z] 15:47:48 INFO - at java.lang.Daemons$FinalizerWatchdogDaemon.waitForObject(Daemons.java:230) [task 2018-05-24T15:47:48.824Z] 15:47:48 INFO - at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:207) [task 2018-05-24T15:47:48.825Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.825Z] 15:47:48 INFO - "FinalizerDaemon" daemon prio=5 tid=7 WAIT [task 2018-05-24T15:47:48.825Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173b358 self=0x2a025638 [task 2018-05-24T15:47:48.826Z] 15:47:48 INFO - | sysTid=783 nice=0 sched=0/0 cgrp=apps handle=704797320 [task 2018-05-24T15:47:48.826Z] 15:47:48 INFO - | state=S schedstat=( 128899845 181014763 89 ) utm=8 stm=4 core=0 [task 2018-05-24T15:47:48.827Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.827Z] 15:47:48 INFO - - waiting on <0x414ba568> (a java.lang.ref.ReferenceQueue) [task 2018-05-24T15:47:48.827Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:401) [task 2018-05-24T15:47:48.828Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102) [task 2018-05-24T15:47:48.828Z] 15:47:48 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73) [task 2018-05-24T15:47:48.828Z] 15:47:48 INFO - at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:170) [task 2018-05-24T15:47:48.829Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.829Z] 15:47:48 INFO - "ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT [task 2018-05-24T15:47:48.829Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173b1f0 self=0x2a045a70 [task 2018-05-24T15:47:48.830Z] 15:47:48 INFO - | sysTid=782 nice=0 sched=0/0 cgrp=apps handle=704929472 [task 2018-05-24T15:47:48.830Z] 15:47:48 INFO - | state=S schedstat=( 13206826 10009656 50 ) utm=0 stm=1 core=0 [task 2018-05-24T15:47:48.831Z] 15:47:48 INFO - at java.lang.Object.wait(Native Method) [task 2018-05-24T15:47:48.831Z] 15:47:48 INFO - - waiting on <0x414ba490> [task 2018-05-24T15:47:48.831Z] 15:47:48 INFO - at java.lang.Object.wait(Object.java:364) [task 2018-05-24T15:47:48.832Z] 15:47:48 INFO - at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:130) [task 2018-05-24T15:47:48.832Z] 15:47:48 INFO - at java.lang.Thread.run(Thread.java:841) [task 2018-05-24T15:47:48.832Z] 15:47:48 INFO - "Compiler" daemon prio=5 tid=5 VMWAIT [task 2018-05-24T15:47:48.833Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173b100 self=0x2a045418 [task 2018-05-24T15:47:48.833Z] 15:47:48 INFO - | sysTid=781 nice=0 sched=0/0 cgrp=apps handle=704926160 [task 2018-05-24T15:47:48.833Z] 15:47:48 INFO - | state=S schedstat=( 1855315238 1206872489 3932 ) utm=106 stm=79 core=0 [task 2018-05-24T15:47:48.834Z] 15:47:48 INFO - #00 pc 0001c5a4 /system/lib/libc.so (__futex_syscall3+8) [task 2018-05-24T15:47:48.834Z] 15:47:48 INFO - #01 pc 0000e688 /system/lib/libc.so (__pthread_cond_timedwait_relative+48) [task 2018-05-24T15:47:48.835Z] 15:47:48 INFO - #02 pc 0000e6e8 /system/lib/libc.so (__pthread_cond_timedwait+64) [task 2018-05-24T15:47:48.835Z] 15:47:48 INFO - #03 pc 00072c9b /system/lib/libdvm.so [task 2018-05-24T15:47:48.835Z] 15:47:48 INFO - #04 pc 00054151 /system/lib/libdvm.so [task 2018-05-24T15:47:48.836Z] 15:47:48 INFO - #05 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.836Z] 15:47:48 INFO - #06 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.836Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.836Z] 15:47:48 INFO - "JDWP" daemon prio=5 tid=4 VMWAIT [task 2018-05-24T15:47:48.837Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173b018 self=0x2a044d80 [task 2018-05-24T15:47:48.837Z] 15:47:48 INFO - | sysTid=780 nice=0 sched=0/0 cgrp=apps handle=704910640 [task 2018-05-24T15:47:48.838Z] 15:47:48 INFO - | state=S schedstat=( 1158584 1248124 7 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.838Z] 15:47:48 INFO - #00 pc 0001c078 /system/lib/libc.so (recvmsg+8) [task 2018-05-24T15:47:48.838Z] 15:47:48 INFO - #01 pc 00060797 /system/lib/libdvm.so [task 2018-05-24T15:47:48.839Z] 15:47:48 INFO - #02 pc 000609cb /system/lib/libdvm.so [task 2018-05-24T15:47:48.839Z] 15:47:48 INFO - #03 pc 00063687 /system/lib/libdvm.so [task 2018-05-24T15:47:48.839Z] 15:47:48 INFO - #04 pc 00054151 /system/lib/libdvm.so [task 2018-05-24T15:47:48.840Z] 15:47:48 INFO - #05 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.840Z] 15:47:48 INFO - #06 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.840Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.841Z] 15:47:48 INFO - "Signal Catcher" daemon prio=5 tid=3 RUNNABLE [task 2018-05-24T15:47:48.841Z] 15:47:48 INFO - | group="system" sCount=0 dsCount=0 obj=0x4173af20 self=0x2a044930 [task 2018-05-24T15:47:48.842Z] 15:47:48 INFO - | sysTid=779 nice=0 sched=0/0 cgrp=apps handle=704716120 [task 2018-05-24T15:47:48.842Z] 15:47:48 INFO - | state=R schedstat=( 85812875 254332589 26 ) utm=2 stm=6 core=0 [task 2018-05-24T15:47:48.842Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.843Z] 15:47:48 INFO - "GC" daemon prio=5 tid=2 VMWAIT [task 2018-05-24T15:47:48.843Z] 15:47:48 INFO - | group="system" sCount=1 dsCount=0 obj=0x4173ae40 self=0x2a0466c8 [task 2018-05-24T15:47:48.843Z] 15:47:48 INFO - | sysTid=777 nice=0 sched=0/0 cgrp=apps handle=704923312 [task 2018-05-24T15:47:48.844Z] 15:47:48 INFO - | state=S schedstat=( 385428474 954042756 144 ) utm=34 stm=4 core=0 [task 2018-05-24T15:47:48.844Z] 15:47:48 INFO - #00 pc 0001c5a4 /system/lib/libc.so (__futex_syscall3+8) [task 2018-05-24T15:47:48.845Z] 15:47:48 INFO - #01 pc 0000e688 /system/lib/libc.so (__pthread_cond_timedwait_relative+48) [task 2018-05-24T15:47:48.845Z] 15:47:48 INFO - #02 pc 0000e6e8 /system/lib/libc.so (__pthread_cond_timedwait+64) [task 2018-05-24T15:47:48.845Z] 15:47:48 INFO - #03 pc 0007197f /system/lib/libdvm.so [task 2018-05-24T15:47:48.846Z] 15:47:48 INFO - #04 pc 00054151 /system/lib/libdvm.so [task 2018-05-24T15:47:48.846Z] 15:47:48 INFO - #05 pc 0000ca58 /system/lib/libc.so (__thread_entry+72) [task 2018-05-24T15:47:48.846Z] 15:47:48 INFO - #06 pc 0000cbd4 /system/lib/libc.so (pthread_create+208) [task 2018-05-24T15:47:48.847Z] 15:47:48 INFO - at dalvik.system.NativeStart.run(Native Method) [task 2018-05-24T15:47:48.847Z] 15:47:48 INFO - NATIVE THREADS: [task 2018-05-24T15:47:48.847Z] 15:47:48 INFO - "<no name>" sysTid=841 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.848Z] 15:47:48 INFO - | state=S schedstat=( 7444729 31509261 3 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.848Z] 15:47:48 INFO - "<no name>" sysTid=843 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.848Z] 15:47:48 INFO - | state=S schedstat=( 18654593023 9026203395 14505 ) utm=1328 stm=537 core=0 [task 2018-05-24T15:47:48.849Z] 15:47:48 INFO - "<no name>" sysTid=847 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.849Z] 15:47:48 INFO - | state=S schedstat=( 294623910 263303349 834 ) utm=11 stm=18 core=0 [task 2018-05-24T15:47:48.850Z] 15:47:48 INFO - "<no name>" sysTid=848 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.850Z] 15:47:48 INFO - | state=S schedstat=( 2746148873 2529215512 441 ) utm=233 stm=41 core=0 [task 2018-05-24T15:47:48.850Z] 15:47:48 INFO - "<no name>" sysTid=849 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.851Z] 15:47:48 INFO - | state=S schedstat=( 6696522980 4365964311 728 ) utm=212 stm=457 core=0 [task 2018-05-24T15:47:48.851Z] 15:47:48 INFO - "<no name>" sysTid=851 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.851Z] 15:47:48 INFO - | state=S schedstat=( 2616666412 3148062709 16614 ) utm=98 stm=163 core=0 [task 2018-05-24T15:47:48.852Z] 15:47:48 INFO - "<no name>" sysTid=852 nice=1 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.852Z] 15:47:48 INFO - | state=S schedstat=( 2003857 12384112 2 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.853Z] 15:47:48 INFO - "<no name>" sysTid=859 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.853Z] 15:47:48 INFO - | state=S schedstat=( 32447625093 23237521442 44650 ) utm=1920 stm=1324 core=0 [task 2018-05-24T15:47:48.853Z] 15:47:48 INFO - "<no name>" sysTid=860 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.854Z] 15:47:48 INFO - | state=S schedstat=( 189245288 260952536 35 ) utm=16 stm=2 core=0 [task 2018-05-24T15:47:48.854Z] 15:47:48 INFO - "<no name>" sysTid=862 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.854Z] 15:47:48 INFO - | state=S schedstat=( 2185357 14935806 3 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.855Z] 15:47:48 INFO - "<no name>" sysTid=864 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.855Z] 15:47:48 INFO - | state=S schedstat=( 167547299 58584588 218 ) utm=13 stm=3 core=0 [task 2018-05-24T15:47:48.855Z] 15:47:48 INFO - "<no name>" sysTid=871 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.856Z] 15:47:48 INFO - | state=S schedstat=( 20589407 38747863 5 ) utm=2 stm=0 core=0 [task 2018-05-24T15:47:48.856Z] 15:47:48 INFO - "<no name>" sysTid=878 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.856Z] 15:47:48 INFO - | state=S schedstat=( 2075118000 709894756 2322 ) utm=25 stm=182 core=0 [task 2018-05-24T15:47:48.857Z] 15:47:48 INFO - "<no name>" sysTid=880 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.857Z] 15:47:48 INFO - | state=S schedstat=( 25376667 82317500 84 ) utm=2 stm=0 core=0 [task 2018-05-24T15:47:48.858Z] 15:47:48 INFO - "<no name>" sysTid=881 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.858Z] 15:47:48 INFO - | state=S schedstat=( 2804993 1961368 2 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.858Z] 15:47:48 INFO - "<no name>" sysTid=882 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.859Z] 15:47:48 INFO - | state=S schedstat=( 1366072 19751962 2 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.859Z] 15:47:48 INFO - "<no name>" sysTid=883 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.859Z] 15:47:48 INFO - | state=S schedstat=( 2662818 16417831 6 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.860Z] 15:47:48 INFO - "<no name>" sysTid=897 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.860Z] 15:47:48 INFO - | state=S schedstat=( 23972618 24901077 13 ) utm=1 stm=1 core=0 [task 2018-05-24T15:47:48.860Z] 15:47:48 INFO - "<no name>" sysTid=907 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.861Z] 15:47:48 INFO - | state=S schedstat=( 118721695 85286973 60 ) utm=11 stm=0 core=0 [task 2018-05-24T15:47:48.861Z] 15:47:48 INFO - "<no name>" sysTid=908 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.862Z] 15:47:48 INFO - | state=S schedstat=( 600920685 938941750 107 ) utm=50 stm=10 core=0 [task 2018-05-24T15:47:48.862Z] 15:47:48 INFO - "<no name>" sysTid=921 nice=1 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.862Z] 15:47:48 INFO - | state=S schedstat=( 109447851 227687952 34 ) utm=6 stm=4 core=0 [task 2018-05-24T15:47:48.863Z] 15:47:48 INFO - "<no name>" sysTid=922 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.863Z] 15:47:48 INFO - | state=S schedstat=( 5664611 5250591 2 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.863Z] 15:47:48 INFO - "<no name>" sysTid=923 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.864Z] 15:47:48 INFO - | state=S schedstat=( 2609803 21921140 4 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.864Z] 15:47:48 INFO - "<no name>" sysTid=924 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.864Z] 15:47:48 INFO - | state=S schedstat=( 1467084 4759788 1 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.865Z] 15:47:48 INFO - "<no name>" sysTid=925 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.865Z] 15:47:48 INFO - | state=S schedstat=( 1484748 4529293 1 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.866Z] 15:47:48 INFO - "<no name>" sysTid=926 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.866Z] 15:47:48 INFO - | state=S schedstat=( 2851978 19250072 4 ) utm=0 stm=0 core=0 [task 2018-05-24T15:47:48.866Z] 15:47:48 INFO - "<no name>" sysTid=927 nice=0 sched=0/0 cgrp=apps [task 2018-05-24T15:47:48.867Z] 15:47:48 INFO - | state=S schedstat=( 338443847 549549398 131 ) utm=22 stm=11 core=0 [task 2018-05-24T15:47:48.867Z] 15:47:48 INFO - ----- end 774 -----
The important lines here are a bit earlier: https://treeherder.mozilla.org/logviewer.html#?job_id=180024212&repo=mozilla-inbound&lineNumber=1583-1590 > [task 2018-05-24T15:32:53.195Z] 15:32:53 INFO - launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_PROCESS_LOG=/tmp/tmpwim_kzpidlog --es env8 NO_EM_RESTART=1 --es args '-no-remote -profile /sdcard/tests/reftest/profile/' --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env2 R_LOG_VERBOSE=1 --es env1 XPCOM_DEBUG_BREAK=stack --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_CRASHREPORTER_NO_REPORT=1 --es env6 R_LOG_DESTINATION=stderr --es env5 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env4 MOZ_IN_AUTOMATION=1 --es env10 R_LOG_LEVEL=6 > .. > [task 2018-05-24T15:47:33.083Z] 15:47:33 INFO - Browser unexpectedly found running. Killing... Not sure why the harness complains about the browser unexpectedly running. Jeff any idea?
Flags: needinfo?(gbrown)
"Browser unexpectedly found running" is expected after some remoteautomation timeouts. https://dxr.mozilla.org/mozilla-central/rev/5866d6685849311f057e7e229b9ace63a2641c29/build/mobile/remoteautomation.py#85-90 The harness waited for the browser to run tests and finish, but instead, the no output timeout was reached, so after the wait finished, the browser was still running and it was subsequently killed. The logging can be a little confusing, but everything is working as intended (except that android debug reftests sometimes hang on startup). There's a long-standing bug for "application timed out after 670 seconds with no output"; this one was opened because a typo was briefly introduced (it's fixed now). Let's dup...
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 7 years ago
Flags: needinfo?(gbrown)
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.