Closed Bug 1115788 Opened 10 years ago Closed 9 years ago

Intermittent test_app_enabled.html | application timed out after 330 seconds with no output

Categories

(Core Graveyard :: DOM: Apps, defect)

36 Branch
ARM
Android
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: KWierso, Unassigned)

Details

(Keywords: intermittent-failure)

14:38:37 INFO - 167 INFO TEST-START | dom/apps/tests/test_app_enabled.html
14:44:22 INFO - org.mozilla.fennec still alive after SIGABRT: waiting...
14:44:27 INFO - org.mozilla.fennec still alive after SIGABRT: waiting...
14:44:32 INFO - org.mozilla.fennec still alive after SIGABRT: waiting...
14:44:37 WARNING - TEST-UNEXPECTED-FAIL | dom/apps/tests/test_app_enabled.html | application timed out after 330 seconds with no output
14:44:37 INFO - INFO | automation.py | Application ran for: 0:09:03.064286
14:44:37 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpuDsyvlpidlog
14:44:37 INFO - Contents of /data/anr/traces.txt:
14:44:37 INFO - ----- pid 2253 at 2014-12-26 14:44:18 -----
14:44:37 INFO - Cmd line: org.mozilla.fennec
14:44:37 INFO - DALVIK THREADS:
14:44:37 INFO - (mutexes: tll=0 tsl=0 tscl=0 ghl=0)
14:44:37 INFO - "main" prio=5 tid=1 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x40baa460 self=0x783830
14:44:37 INFO - | sysTid=2253 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=1074668708
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=2026 stm=196 core=0
14:44:37 INFO - at android.os.MessageQueue.nativePollOnce(Native Method)
14:44:37 INFO - at android.os.MessageQueue.next(MessageQueue.java:118)
14:44:37 INFO - at android.os.Looper.loop(Looper.java:118)
14:44:37 INFO - at android.app.ActivityThread.main(ActivityThread.java:4424)
14:44:37 INFO - at java.lang.reflect.Method.invokeNative(Native Method)
14:44:37 INFO - at java.lang.reflect.Method.invoke(Method.java:511)
14:44:37 INFO - at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
14:44:37 INFO - at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
14:44:37 INFO - at dalvik.system.NativeStart.main(Native Method)
14:44:37 INFO - "pool-1-thread-1" prio=5 tid=21 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x413a6658 self=0xc17f00
14:44:37 INFO - | sysTid=2333 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=12637736
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=37 stm=19 core=1
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x413a9498> (a java.lang.VMThread) held by tid=21 (pool-1-thread-1)
14:44:37 INFO - at java.lang.Thread.parkFor(Thread.java:1231)
14:44:37 INFO - at sun.misc.Unsafe.park(Unsafe.java:323)
14:44:37 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
14:44:37 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
14:44:37 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@4132e958" daemon prio=5 tid=20 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x4134b610 self=0xb3ee70
14:44:37 INFO - | sysTid=2332 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=11793112
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x413565d8> (a java.lang.ref.ReferenceQueue)
14:44:37 INFO - at java.lang.Object.wait(Object.java:401)
14:44:37 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
14:44:37 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
14:44:37 INFO - at org.apache.http.impl.conn.tsccm.RefQueueWorker.run(RefQueueWorker.java:102)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "Thread-100" prio=5 tid=18 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41319bf8 self=0xafe920
14:44:37 INFO - | sysTid=2305 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=11046992
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=1088 stm=404 core=0
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "actionMode" prio=5 tid=17 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41397ac8 self=0xa915f8
14:44:37 INFO - | sysTid=2279 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9259672
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x41397ac8> (a java.util.Timer$TimerImpl)
14:44:37 INFO - at java.lang.Object.wait(Object.java:364)
14:44:37 INFO - at java.util.Timer$TimerImpl.run(Timer.java:214)
14:44:37 INFO - "pool-3-thread-1" prio=5 tid=16 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41326a38 self=0x94b658
14:44:37 INFO - | sysTid=2277 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9820624
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=0
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x41326b80> (a java.lang.VMThread) held by tid=16 (pool-3-thread-1)
14:44:37 INFO - at java.lang.Thread.parkFor(Thread.java:1231)
14:44:37 INFO - at sun.misc.Unsafe.park(Unsafe.java:323)
14:44:37 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
14:44:37 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
14:44:37 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "GeckoANRReporter" daemon prio=5 tid=15 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x412f69b0 self=0x94c368
14:44:37 INFO - | sysTid=2274 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9680432
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=0
14:44:37 INFO - at android.os.MessageQueue.nativePollOnce(Native Method)
14:44:37 INFO - at android.os.MessageQueue.next(MessageQueue.java:118)
14:44:37 INFO - at android.os.Looper.loop(Looper.java:118)
14:44:37 INFO - at org.mozilla.gecko.ANRReporter$1.run(ANRReporter.java:97)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "Gecko" prio=5 tid=13 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x412f6448 self=0x93b1e0
14:44:37 INFO - | sysTid=2273 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9534696
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=7957 stm=474 core=1
14:44:37 INFO - at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method)
14:44:37 INFO - at org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:371)
14:44:37 INFO - at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:184)
14:44:37 INFO - "pool-2-thread-1" prio=5 tid=14 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x412c5c88 self=0x943848
14:44:37 INFO - | sysTid=2272 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9198688
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=2 core=1
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x412c5dd0> (a java.lang.VMThread) held by tid=14 (pool-2-thread-1)
14:44:37 INFO - at java.lang.Thread.parkFor(Thread.java:1231)
14:44:37 INFO - at sun.misc.Unsafe.park(Unsafe.java:323)
14:44:37 INFO - at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
14:44:37 INFO - at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
14:44:37 INFO - at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
14:44:37 INFO - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "GeckoBackgroundThread" daemon prio=5 tid=12 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x412bbcb0 self=0x920328
14:44:37 INFO - | sysTid=2268 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9252984
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=171 stm=67 core=1
14:44:37 INFO - at android.os.MessageQueue.nativePollOnce(Native Method)
14:44:37 INFO - at android.os.MessageQueue.next(MessageQueue.java:118)
14:44:37 INFO - at android.os.Looper.loop(Looper.java:118)
14:44:37 INFO - at org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:43)
14:44:37 INFO - "Binder Thread #3" prio=5 tid=11 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x4120b2d0 self=0x9574e8
14:44:37 INFO - | sysTid=2267 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9076368
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "Binder Thread #2" prio=5 tid=10 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x4120a748 self=0x94a7c0
14:44:37 INFO - | sysTid=2266 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9381280
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "Binder Thread #1" prio=5 tid=9 NATIVE
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x412057b8 self=0x952790
14:44:37 INFO - | sysTid=2265 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9386136
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "FinalizerWatchdogDaemon" daemon prio=5 tid=8 TIMED_WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41201e68 self=0x8a3080
14:44:37 INFO - | sysTid=2264 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9388272
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at java.lang.VMThread.sleep(Native Method)
14:44:37 INFO - at java.lang.Thread.sleep(Thread.java:1031)
14:44:37 INFO - at java.lang.Thread.sleep(Thread.java:1013)
14:44:37 INFO - at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:213)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "FinalizerDaemon" daemon prio=5 tid=7 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41201d10 self=0x941ff0
14:44:37 INFO - | sysTid=2263 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9245504
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=19 stm=3 core=0
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x40ba05d0> (a java.lang.ref.ReferenceQueue)
14:44:37 INFO - at java.lang.Object.wait(Object.java:401)
14:44:37 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
14:44:37 INFO - at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
14:44:37 INFO - at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:168)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
14:44:37 INFO - | group="main" sCount=1 dsCount=0 obj=0x41201ba8 self=0x95b808
14:44:37 INFO - | sysTid=2261 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9226168
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=3 stm=0 core=0
14:44:37 INFO - at java.lang.Object.wait(Native Method)
14:44:37 INFO - - waiting on <0x40ba04f8>
14:44:37 INFO - at java.lang.Object.wait(Object.java:364)
14:44:37 INFO - at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:128)
14:44:37 INFO - at java.lang.Thread.run(Thread.java:856)
14:44:37 INFO - "Compiler" daemon prio=5 tid=5 VMWAIT
14:44:37 INFO - | group="system" sCount=1 dsCount=0 obj=0x41201ab8 self=0x947c10
14:44:37 INFO - | sysTid=2260 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9164584
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=82 stm=67 core=0
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "JDWP" daemon prio=5 tid=4 VMWAIT
14:44:37 INFO - | group="system" sCount=1 dsCount=0 obj=0x412019d0 self=0x809260
14:44:37 INFO - | sysTid=2259 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9247000
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=1
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "Signal Catcher" daemon prio=5 tid=3 RUNNABLE
14:44:37 INFO - | group="system" sCount=0 dsCount=0 obj=0x412018d8 self=0x905d18
14:44:37 INFO - | sysTid=2257 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9172560
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=0 stm=0 core=0
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - "GC" daemon prio=5 tid=2 VMWAIT
14:44:37 INFO - | group="system" sCount=1 dsCount=0 obj=0x412017f8 self=0x9283e8
14:44:37 INFO - | sysTid=2256 nice=0 sched=0/0 cgrp=[fopen-error:2] handle=9227048
14:44:37 INFO - | schedstat=( 0 0 0 ) utm=214 stm=8 core=0
14:44:37 INFO - at dalvik.system.NativeStart.run(Native Method)
14:44:37 INFO - ----- end 2253 -----
14:44:38 INFO - /data/tombstones does not exist; tombstone check skipped
14:44:39 INFO - mozcrash Downloading symbols from: https://ftp-ssl.mozilla.org/pub/mozilla.org/mobile/tinderbox-builds/fx-team-android-api-11/1419631116/fennec-37.0a1.en-US.android-arm.crashreporter-symbols.zip
14:44:41 INFO - mozcrash Saved minidump as /builds/panda-0131/test/build/blobber_upload_dir/173f8e32-c573-2cba-05818da0-6037176b.dmp
14:44:41 INFO - mozcrash Saved app info as /builds/panda-0131/test/build/blobber_upload_dir/173f8e32-c573-2cba-05818da0-6037176b.extra
14:44:41 WARNING - PROCESS-CRASH | dom/apps/tests/test_app_enabled.html | application crashed [None]
14:44:41 INFO - Crash dump filename: /tmp/tmpTeOT3u/173f8e32-c573-2cba-05818da0-6037176b.dmp
14:44:41 INFO - stderr from minidump_stackwalk:
14:44:41 INFO - 2014-12-26 14:44:41: minidump_processor.cc:264: INFO: Processing minidump in file /tmp/tmpTeOT3u/173f8e32-c573-2cba-05818da0-6037176b.dmp
14:44:41 INFO - 2014-12-26 14:44:41: minidump.cc:3815: INFO: Minidump opened minidump /tmp/tmpTeOT3u/173f8e32-c573-2cba-05818da0-6037176b.dmp
14:44:41 INFO - 2014-12-26 14:44:41: minidump.cc:3847: ERROR: Minidump header signature mismatch: (0x0, 0x0) != 0x504d444d
14:44:41 INFO - 2014-12-26 14:44:41: minidump_processor.cc:268: ERROR: Minidump /tmp/tmpTeOT3u/173f8e32-c573-2cba-05818da0-6037176b.dmp could not be read
14:44:41 INFO - 2014-12-26 14:44:41: minidump.cc:3787: INFO: Minidump closing minidump
14:44:41 INFO - 2014-12-26 14:44:41: minidump_stackwalk.cc:529: ERROR: MinidumpProcessor::Process failed
14:44:41 INFO - Stopping web server
14:44:41 INFO - Stopping web socket server
14:44:41 INFO - Stopping ssltunnel
14:44:41 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected!
Inactive; closing (see bug 1180138).
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WORKSFORME
Product: Core → Core Graveyard
You need to log in before you can comment on or make changes to this bug.