Watchdog kills system service in system_server *****

本文描述由Watchdog杀掉系统服务而引起sysytem_server退出的issue, 并简要介绍Watchdog机理和简短记录ServerThread的looper线程.

Watchdog 线程发送出Monitor message是由ServerThread的looper接收处理的;

frameworks/base/services/java/com/android/server/SystemServer.java

注意看

"android.server.ServerThread" prio=5 tid=17 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x42684650 self=0x5e2d8500
  | sysTid=330 nice=-2 sched=0/0 cgrp=apps handle=1571273744
  | schedstat=( 145001449310 25103992165 210114 ) utm=11956 stm=2544 core=0
  at com.android.server.am.ActivityManagerService.monitor(ActivityManagerService.java:~15185)
  - waiting to lock <0x4268e870> (a com.android.server.am.ActivityManagerService) held by tid=86 (Binder_A)
  at com.android.server.Watchdog$HeartbeatHandler.handleMessage(Watchdog.java:137)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.ServerThread.run(SystemServer.java:923)

就可以知道watchdog.java在运行Monitor时是卡在那个锁那里了。找到tid=86并观察栈信息。

如何添加service到watchdog?

       // Add ourself to the Watchdog monitors.

     Watchdog.getInstance().addMonitor(this);


This watchdog issue is a very very common issue.
The root cause is that service is blocked on something and is killed by Watchdog, in this case it is Wakelock read.
Root cause may vary such as something like dead lock, waste time operation, etc.

[Symptom]
From the system logcat:

10-02 22:04:46.609 W/Watchdog(  314): *** WATCHDOG KILLING SYSTEM PROCESS: com.android.server.am.ActivityManagerService

10-02 22:04:43.589 I/DEBUG   ( 1775): pid: 314, tid: 314  >>> system_server <<<
10-02 22:04:43.589 I/DEBUG   ( 1775): signal 6 (SIGABRT), code 0 (?), fault addr --------
10-02 22:04:43.589 I/DEBUG   ( 1775):  r0 00d3d228  r1 00000080  r2 00000002  r3 00000000
10-02 22:04:43.589 I/DEBUG   ( 1775):  r4 00d3d228  r5 00000000  r6 00000002  r7 000000f0
10-02 22:04:43.589 I/DEBUG   ( 1775):  r8 00000000  r9 00d3d228  10 00000000  fp 00000001
10-02 22:04:43.589 I/DEBUG   ( 1775):  ip 00000002  sp bebfb118  lr 4003d254  pc 400386e8  cpsr 60000010

10-02 22:04:45.689 I/DEBUG   ( 1775):          #00  pc 0000d6e8  /system/lib/libc.so (__futex_syscall3)
10-02 22:04:45.689 I/DEBUG   ( 1775):          #01  pc 00012250  /system/lib/libc.so (pthread_mutex_lock)
10-02 22:04:46.379 I/DEBUG   ( 1775):          #02  pc 0005d3e6  /system/lib/libdvm.so

Note: The call stack and frame varies and is not important here.

And in the event log:
10-02 22:04:19.349 I/watchdog(  314): com.android.server.am.ActivityManagerService

[Reason]
The reason is ActivityManagerService is killed by watchdog, and cause system server aborted.
The process killed by watchdog may be AcitivityManagerService, PowerManagerService, AlarmManagerService, BatteryService, WindowManagerService, etc.
The system_server thread may receive ABORT signal (sent via System.exit(exitcode) in Watchdog.java) at any execution point, most of which are blocking io and lock waiting.
The execution point of system_server is not important for analysing the issue, while the thread killed by WD is the most important thing which needs deep look up.

Sometimes, the "WATCHDOG KILLING SYSTEM PROCESS" is not printed before system reboots and dumps, and only a system_server SIGABORT. 
More effort is need to find out the PROCESS maybe killed by the WD, and maybe this is not the cause.

ActivityManager is process name of AcitivityManagerService runtime .

In AcitivityManagerService.java
   static class AThread extends Thread {
        ActivityManagerService mService;
        boolean mReady = false;

        public AThread() {
            super("ActivityManager");
        }

        public void run() {
 ....
 }
The name will be passed down to jni, androidCreateThreadEtc, runtime, Thread, pthread, and linux system call as process name.

The whole system_server releated part in BugReport.txt as follows.

----- pid 314 at 2012-10-02 22:04:20 -----
Cmd line: system_server

DALVIK THREADS:
(mutexes: tll=0 tsl=0 tscl=0 ghl=0)
"main" prio=5 tid=1 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x40aebc58 self=0xaece38
  | sysTid=314 nice=0 sched=0/0 cgrp=default handle=1074242808
  | schedstat=( 158943149965 255809449717 466931 ) utm=12577 stm=3317 core=0
  at com.android.server.PowerManagerService.acquireWakeLock(PowerManagerService.java:~820)
  - waiting to lock <0x41141f20> (a com.android.server.PowerManagerService$LockList) held by tid=66 (Binder Thread #6)
  at android.os.IPowerManager$Stub.onTransact(IPowerManager.java:62)
  at android.os.Binder.execTransact(Binder.java:338)
  at com.android.server.SystemServer.init1(Native Method)
  at com.android.server.SystemServer.main(SystemServer.java:861)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:511)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:825)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:592)
  at dalvik.system.NativeStart.main(Native Method)

"Binder Thread #16" prio=5 tid=71 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a80cd8 self=0x15cec98
  | sysTid=8954 nice=0 sched=0/0 cgrp=default handle=18815520
  | schedstat=( 7318944993 13492498275 24356 ) utm=548 stm=183 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #15" prio=5 tid=36 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x416cb970 self=0x151a118
  | sysTid=25687 nice=0 sched=0/0 cgrp=default handle=21477824
  | schedstat=( 31715650198 43454598184 94183 ) utm=2466 stm=705 core=0
  at dalvik.system.NativeStart.run(Native Method)

"loc_eng" prio=5 tid=91 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a340d0 self=0x13e4960
  | sysTid=22222 nice=0 sched=0/0 cgrp=default handle=21083416
  | schedstat=( 396495003 83498338 4909 ) utm=23 stm=16 core=0
  at dalvik.system.NativeStart.run(Native Method)

"java.lang.ProcessManager" daemon prio=5 tid=72 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4125b638 self=0x11f8f70
  | sysTid=5495 nice=0 sched=0/0 cgrp=default handle=18846656
  | schedstat=( 9616667 21646668 53 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x412634b0> (a java.util.HashMap)
  at java.lang.Object.wait(Object.java:364)
  at java.lang.ProcessManager.waitForMoreChildren(ProcessManager.java:140)
  at java.lang.ProcessManager.watchChildren(ProcessManager.java:105)
  at java.lang.ProcessManager.access$000(ProcessManager.java:40)
  at java.lang.ProcessManager$1.run(ProcessManager.java:58)

"pool-2-thread-10" prio=5 tid=90 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x414487f8 self=0xe2d5a8
  | sysTid=3562 nice=0 sched=0/0 cgrp=default handle=16441896
  | schedstat=( 11646904921 2985764972 33803 ) utm=779 stm=385 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41422b10> (a java.lang.VMThread) held by tid=90 (pool-2-thread-10)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-9" prio=5 tid=89 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41633e40 self=0xebfcb8
  | sysTid=3561 nice=0 sched=0/0 cgrp=default handle=19687512
  | schedstat=( 11681874991 3027153313 33836 ) utm=809 stm=359 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4160f7b8> (a java.lang.VMThread) held by tid=89 (pool-2-thread-9)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-8" prio=5 tid=88 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41157080 self=0x129bee0
  | sysTid=3557 nice=0 sched=0/0 cgrp=default handle=19691936
  | schedstat=( 11656568319 2962318370 33879 ) utm=761 stm=404 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x411830d8> (a java.lang.VMThread) held by tid=88 (pool-2-thread-8)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-7" prio=5 tid=87 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x413284a8 self=0x1287138
  | sysTid=3545 nice=0 sched=0/0 cgrp=default handle=15160840
  | schedstat=( 11631698340 2733634976 34392 ) utm=781 stm=382 core=0
  at android.os.BinderProxy.transact(Native Method)
  at com.android.server.wm.WindowManagerService.viewServerWindowCommand(WindowManagerService.java:5771)
  at com.android.server.wm.ViewServer$ViewServerWorker.run(ViewServer.java:249)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:442)
  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:305)
  at java.util.concurrent.FutureTask.run(FutureTask.java:137)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1076)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-6" prio=5 tid=86 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4136b298 self=0x12a3770
  | sysTid=3543 nice=0 sched=0/0 cgrp=default handle=16444864
  | schedstat=( 11692126739 3067643317 33899 ) utm=782 stm=387 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41316ec8> (a java.lang.VMThread) held by tid=86 (pool-2-thread-6)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-5" prio=5 tid=85 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41894e90 self=0x1165550
  | sysTid=3541 nice=0 sched=0/0 cgrp=default handle=15643616
  | schedstat=( 11750740156 2919316631 34275 ) utm=799 stm=376 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41357378> (a java.lang.VMThread) held by tid=85 (pool-2-thread-5)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-4" prio=5 tid=84 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4194efd0 self=0x1287e28
  | sysTid=3540 nice=0 sched=0/0 cgrp=default handle=13329104
  | schedstat=( 11621928327 2657600013 33658 ) utm=775 stm=387 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4136ff50> (a java.lang.VMThread) held by tid=84 (pool-2-thread-4)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-3" prio=5 tid=83 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41209330 self=0x10e43a0
  | sysTid=3539 nice=0 sched=0/0 cgrp=default handle=15668376
  | schedstat=( 11605491621 2717388304 33682 ) utm=801 stm=359 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41391910> (a java.lang.VMThread) held by tid=83 (pool-2-thread-3)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-2" prio=5 tid=82 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x419f6640 self=0xe23d80
  | sysTid=3523 nice=0 sched=0/0 cgrp=default handle=18065304
  | schedstat=( 11652096557 2786339999 33782 ) utm=780 stm=385 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41695868> (a java.lang.VMThread) held by tid=82 (pool-2-thread-2)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"pool-2-thread-1" prio=5 tid=78 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41a03490 self=0xeebc90
  | sysTid=3522 nice=0 sched=0/0 cgrp=default handle=13870560
  | schedstat=( 11638589981 3062699973 33610 ) utm=819 stm=344 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x413c9508> (a java.lang.VMThread) held by tid=78 (pool-2-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"Remote View Server [port=4939]" prio=5 tid=57 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41256b38 self=0xe7f438
  | sysTid=3491 nice=0 sched=0/0 cgrp=default handle=14368224
  | schedstat=( 112742188630 119737471359 243704 ) utm=10294 stm=980 core=0
  at libcore.io.Posix.accept(Native Method)
  at libcore.io.BlockGuardOs.accept(BlockGuardOs.java:55)
  at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:98)
  at java.net.ServerSocket.implAccept(ServerSocket.java:202)
  at java.net.ServerSocket.accept(ServerSocket.java:127)
  at com.android.server.wm.ViewServer.run(ViewServer.java:166)
  at java.lang.Thread.run(Thread.java:856)

"AsyncTask #1" prio=5 tid=81 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x417d9b58 self=0xea8dd0
  | sysTid=2375 nice=10 sched=0/0 cgrp=bg_non_interactive handle=15372832
  | schedstat=( 985001 985009998 6 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x411c6da0> (a java.lang.VMThread) held by tid=81 (AsyncTask #1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"Thread-170" prio=5 tid=76 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41397f48 self=0xe80990
  | sysTid=2085 nice=0 sched=0/0 cgrp=default handle=15931408
  | schedstat=( 921668 6643333 6 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x416d59b8> (a com.sonyericsson.android.server.dormant.PacketWatcher)
  at java.lang.Object.wait(Object.java:364)
  at com.sonyericsson.android.server.dormant.PacketWatcher.sleepUntilNotify(PacketWatcher.java:126)
  at com.sonyericsson.android.server.dormant.PacketWatcher.run(PacketWatcher.java:105)
  at java.lang.Thread.run(Thread.java:856)

"Binder Thread #14" prio=5 tid=80 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411db070 self=0xda51f0
  | sysTid=1558 nice=0 sched=0/0 cgrp=default handle=15846608
  | schedstat=( 159055323384 250676669775 463656 ) utm=12463 stm=3442 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #13" prio=5 tid=79 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41354f08 self=0xe228f0
  | sysTid=1557 nice=0 sched=0/0 cgrp=default handle=14776728
  | schedstat=( 159819586690 256724026803 465109 ) utm=12617 stm=3364 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #12" prio=5 tid=77 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4131fef0 self=0xf1c7f8
  | sysTid=1556 nice=0 sched=0/0 cgrp=default handle=14865312
  | schedstat=( 160018036898 251791399873 461722 ) utm=12585 stm=3416 core=0
  at dalvik.system.NativeStart.run(Native Method)

"SyncHandler-0" prio=5 tid=75 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x415f74a0 self=0xd98f30
  | sysTid=1250 nice=0 sched=0/0 cgrp=default handle=14419712
  | schedstat=( 766667 3178333 10 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"Binder Thread #11" prio=5 tid=74 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41672dc8 self=0xd88eb8
  | sysTid=1230 nice=0 sched=0/0 cgrp=default handle=13891880
  | schedstat=( 159444249831 252733740172 464613 ) utm=12552 stm=3392 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #10" prio=5 tid=70 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4132bfe0 self=0xda6eb0
  | sysTid=1229 nice=0 sched=0/0 cgrp=default handle=14427952
  | schedstat=( 158662615529 254469564929 463543 ) utm=12440 stm=3426 core=0
  at dalvik.system.NativeStart.run(Native Method)

"GpsLocationProvider" prio=5 tid=73 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41136e30 self=0xcf1768
  | sysTid=1103 nice=10 sched=0/0 cgrp=bg_non_interactive handle=13852432
  | schedstat=( 8931619924 352495106678 35863 ) utm=730 stm=163 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at com.android.server.location.GpsLocationProvider$GpsLocationProviderThread.run(GpsLocationProvider.java:2295)

"Binder Thread #9" prio=5 tid=69 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x413876f8 self=0xdee480
  | sysTid=986 nice=0 sched=0/0 cgrp=default handle=14612936
  | schedstat=( 159196835428 253561806311 463891 ) utm=12498 stm=3421 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #8" prio=5 tid=67 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x416076d8 self=0xdeceb0
  | sysTid=956 nice=0 sched=0/0 cgrp=default handle=14610136
  | schedstat=( 157685381444 253174018347 465440 ) utm=12399 stm=3369 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #7" prio=5 tid=68 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x413d8d80 self=0xde9220
  | sysTid=923 nice=0 sched=0/0 cgrp=default handle=14583960
  | schedstat=( 160190188421 253860725054 464553 ) utm=12662 stm=3357 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #6" prio=5 tid=66 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x4131b6b0 self=0xddbd50
  | sysTid=915 nice=0 sched=0/0 cgrp=default handle=14531632
  | schedstat=( 158993650051 250847722838 462204 ) utm=12663 stm=3236 core=0
  at com.android.server.am.BatteryStatsService.noteStopWakelock(BatteryStatsService.java:~115)
  - waiting to lock <0x41148130> (a com.android.internal.os.BatteryStatsImpl) held by tid=15 (ProcessStats)
  at com.android.server.PowerManagerService.noteStopWakeLocked(PowerManagerService.java:854)
  at com.android.server.PowerManagerService.releaseWakeLockLocked(PowerManagerService.java:1088)
  at com.android.server.PowerManagerService.releaseWakeLock(PowerManagerService.java:1032)
  at android.os.IPowerManager$Stub.onTransact(IPowerManager.java:109)
  at android.os.Binder.execTransact(Binder.java:338)
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #5" prio=5 tid=65 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x41207710 self=0xdd3570
  | sysTid=890 nice=0 sched=0/0 cgrp=default handle=14458000
  | schedstat=( 158613715817 256865951483 466002 ) utm=12410 stm=3451 core=0
  at com.android.server.am.BatteryStatsService.notePhoneDataConnectionState(BatteryStatsService.java:~218)
  - waiting to lock <0x41148130> (a com.android.internal.os.BatteryStatsImpl) held by tid=15 (ProcessStats)
  at com.android.internal.app.IBatteryStats$Stub.onTransact(IBatteryStats.java:239)
  at android.os.Binder.execTransact(Binder.java:338)
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #4" prio=5 tid=64 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x411de330 self=0xdd2e68
  | sysTid=888 nice=0 sched=0/0 cgrp=default handle=14458992
  | schedstat=( 157375788133 251517408288 464794 ) utm=12362 stm=3375 core=0
  at com.android.server.am.ActivityManagerService.appDiedLocked(ActivityManagerService.java:~2899)
  - waiting to lock <0x41148130> (a com.android.internal.os.BatteryStatsImpl) held by tid=15 (ProcessStats)
  at com.android.server.am.ActivityManagerService$AppDeathRecipient.binderDied(ActivityManagerService.java:888)
  at android.os.BinderProxy.sendDeathNotice(Binder.java:417)
  at dalvik.system.NativeStart.run(Native Method)

"NetworkTimeUpdateService" prio=5 tid=63 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4137d928 self=0xdc5b68
  | sysTid=842 nice=0 sched=0/0 cgrp=default handle=14442424
  | schedstat=( 65703333 152971671 138 ) utm=3 stm=3 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"ThrottleService" prio=5 tid=62 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41771f40 self=0xdc50c0
  | sysTid=840 nice=0 sched=0/0 cgrp=default handle=14439696
  | schedstat=( 1220013354 1713178319 2842 ) utm=77 stm=45 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"CountryDetectorService" prio=5 tid=61 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4192cb90 self=0xdc49e0
  | sysTid=838 nice=10 sched=0/0 cgrp=bg_non_interactive handle=14430048
  | schedstat=( 3403068316 421379463271 32694 ) utm=228 stm=112 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at com.android.server.CountryDetectorService.run(CountryDetectorService.java:195)
  at java.lang.Thread.run(Thread.java:856)

"LocationManagerService" prio=5 tid=60 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4115d818 self=0xdc4388
  | sysTid=836 nice=10 sched=0/0 cgrp=bg_non_interactive handle=14194352
  | schedstat=( 542091667 41901311662 1496 ) utm=32 stm=22 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at com.android.server.LocationManagerService.run(LocationManagerService.java:598)
  at java.lang.Thread.run(Thread.java:856)

"watchdog" prio=5 tid=59 SUSPENDED
  | group="main" sCount=1 dsCount=0 obj=0x41142a78 self=0xcf6758
  | sysTid=825 nice=0 sched=0/0 cgrp=default handle=13154080
  | schedstat=( 718493338 288991684 4970 ) utm=33 stm=38 core=0
  at java.lang.Object.wait(Native Method)
  at java.lang.Object.wait(Object.java:401)
  at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:3018)
  at com.android.server.am.ActivityManagerService.dumpStackTraces(ActivityManagerService.java:2996)
  at com.android.server.Watchdog.run(Watchdog.java:547)

"Binder Thread #3" prio=5 tid=58 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41216268 self=0xc8e370
  | sysTid=708 nice=0 sched=0/0 cgrp=default handle=13448296
  | schedstat=( 159365749989 252798150133 463182 ) utm=12594 stm=3342 core=0
  at dalvik.system.NativeStart.run(Native Method)

"pool-1-thread-1" prio=5 tid=56 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4120b7c0 self=0xc75718
  | sysTid=684 nice=0 sched=0/0 cgrp=default handle=13066344
  | schedstat=( 340581648 1288058312 1867 ) utm=16 stm=18 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41177bc0> (a java.lang.VMThread) held by tid=56 (pool-1-thread-1)
  at java.lang.Thread.parkFor(Thread.java:1231)
  at sun.misc.Unsafe.park(Unsafe.java:323)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2022)
  at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:413)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1009)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1069)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
  at java.lang.Thread.run(Thread.java:856)

"RefQueueWorker@org.apache.http.impl.conn.tsccm.ConnPoolByRoute@4129fdd0" daemon prio=5 tid=55 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41a0bfb8 self=0xbe15d8
  | sysTid=673 nice=0 sched=0/0 cgrp=default handle=13548192
  | schedstat=( 223333 5576666 3 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x4164c2c8> (a java.lang.ref.ReferenceQueue)
  at java.lang.Object.wait(Object.java:401)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
  at org.apache.http.impl.conn.tsccm.RefQueueWorker.run(RefQueueWorker.java:102)
  at java.lang.Thread.run(Thread.java:856)

"CTSA Inject Thread" prio=5 tid=54 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411fb500 self=0xd16100
  | sysTid=671 nice=-8 sched=0/0 cgrp=default handle=13722960
  | schedstat=( 540001 7650000 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"Thread-64" prio=5 tid=53 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x411d1d28 self=0xd225f0
  | sysTid=670 nice=0 sched=0/0 cgrp=default handle=13746160
  | schedstat=( 208332 1145002 3 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x41130550> (a java.util.LinkedList)
  at java.lang.Object.wait(Object.java:364)
  at com.android.internal.atfwd.AtCkpdCmdHandler$1.run(AtCkpdCmdHandler.java:226)

"backup" prio=5 tid=52 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a1a1e0 self=0xd20e20
  | sysTid=666 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12462528
  | schedstat=( 822435027 143918403293 6594 ) utm=56 stm=26 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"UsbDeviceManager" prio=5 tid=51 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a47bd0 self=0xc8bf10
  | sysTid=665 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12278952
  | schedstat=( 17721667 1162528332 70 ) utm=1 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"AudioService" prio=5 tid=50 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41974730 self=0xbb6558
  | sysTid=664 nice=0 sched=0/0 cgrp=default handle=13595216
  | schedstat=( 3093708259 3955360056 23091 ) utm=175 stm=134 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.media.AudioService$AudioSystemThread.run(AudioService.java:2220)

"VoldConnector.CallbackHandler" prio=5 tid=49 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411ca738 self=0xcf3060
  | sysTid=663 nice=0 sched=0/0 cgrp=default handle=13624104
  | schedstat=( 1376664 14350002 10 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"VoldConnector" prio=5 tid=48 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a27c38 self=0xd16e80
  | sysTid=662 nice=0 sched=0/0 cgrp=default handle=13171000
  | schedstat=( 10156672 25673329 41 ) utm=1 stm=0 core=0
  at android.net.LocalSocketImpl.readba_native(Native Method)
  at android.net.LocalSocketImpl.access$400(LocalSocketImpl.java:29)
  at android.net.LocalSocketImpl$SocketInputStream.read(LocalSocketImpl.java:92)
  at com.android.server.NativeDaemonConnector.listenToSocket(NativeDaemonConnector.java:132)
  at com.android.server.NativeDaemonConnector.run(NativeDaemonConnector.java:90)
  at java.lang.Thread.run(Thread.java:856)

"MountService-worker" prio=5 tid=47 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41715a68 self=0xd169a8
  | sysTid=661 nice=0 sched=0/0 cgrp=default handle=13170936
  | schedstat=( 11763333 56383330 68 ) utm=1 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"MountService" prio=5 tid=46 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x415c1248 self=0xc967b0
  | sysTid=660 nice=0 sched=0/0 cgrp=default handle=13200384
  | schedstat=( 628334 759999 7 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"WifiWatchdogStateMachine" prio=5 tid=45 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4164e7d0 self=0xd212f0
  | sysTid=659 nice=0 sched=0/0 cgrp=default handle=13768512
  | schedstat=( 180225007 271383335 667 ) utm=9 stm=9 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"Tethering" prio=5 tid=44 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41293740 self=0xbe0588
  | sysTid=658 nice=0 sched=0/0 cgrp=default handle=13597232
  | schedstat=( 312741643 1242096665 1357 ) utm=21 stm=10 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"ConnectivityServiceThread" prio=5 tid=43 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x415cfa48 self=0xd1e948
  | sysTid=657 nice=0 sched=0/0 cgrp=default handle=13655416
  | schedstat=( 29972246768 141886424843 113110 ) utm=1821 stm=1176 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"WifiService" prio=5 tid=42 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41673a38 self=0xc747f0
  | sysTid=656 nice=0 sched=0/0 cgrp=default handle=13061184
  | schedstat=( 888029973 334665004 1545 ) utm=37 stm=51 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"WifiStateMachine" prio=5 tid=41 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4124a300 self=0xbdd118
  | sysTid=654 nice=0 sched=0/0 cgrp=default handle=13071280
  | schedstat=( 4167178378 21030324981 14809 ) utm=313 stm=103 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"WifiP2pService" prio=5 tid=40 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x415bb8a0 self=0xcd4a30
  | sysTid=653 nice=0 sched=0/0 cgrp=default handle=13632136
  | schedstat=( 3843329 25556669 32 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"NetworkPolicy" prio=5 tid=39 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4160fcd8 self=0xc750a8
  | sysTid=652 nice=0 sched=0/0 cgrp=default handle=13192176
  | schedstat=( 142584096234 445844810336 456482 ) utm=12458 stm=1800 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"NetworkStats" prio=5 tid=38 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411faf68 self=0xc78e38
  | sysTid=651 nice=0 sched=0/0 cgrp=default handle=12279032
  | schedstat=( 114063511640 301561091721 149213 ) utm=10324 stm=1082 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"NetdConnector.CallbackHandler" prio=5 tid=37 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41141018 self=0xbdffc0
  | sysTid=650 nice=0 sched=0/0 cgrp=default handle=13570784
  | schedstat=( 1054380010 2522063326 1737 ) utm=87 stm=18 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"NetdConnector" prio=5 tid=20 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4115e910 self=0xd1d428
  | sysTid=649 nice=0 sched=0/0 cgrp=default handle=13779152
  | schedstat=( 5615274885 7393128439 12514 ) utm=450 stm=111 core=0
  at android.net.LocalSocketImpl.readba_native(Native Method)
  at android.net.LocalSocketImpl.access$400(LocalSocketImpl.java:29)
  at android.net.LocalSocketImpl$SocketInputStream.read(LocalSocketImpl.java:92)
  at com.android.server.NativeDaemonConnector.listenToSocket(NativeDaemonConnector.java:132)
  at com.android.server.NativeDaemonConnector.run(NativeDaemonConnector.java:90)
  at java.lang.Thread.run(Thread.java:856)

"Thread-44" prio=5 tid=35 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x413274c0 self=0xd609f8
  | sysTid=430 nice=0 sched=0/0 cgrp=default handle=14026480
  | schedstat=( 158334 325000 3 ) utm=0 stm=0 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x416d7008> (a java.lang.Object)
  at java.lang.Object.wait(Object.java:364)
  at com.android.server.SamplingRateChangeProcessor.run(CpuGovernorService.java:406)
  at java.lang.Thread.run(Thread.java:856)

"BluetoothAdapterStateMachine" prio=5 tid=34 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41649678 self=0xd5f580
  | sysTid=429 nice=0 sched=0/0 cgrp=default handle=14023120
  | schedstat=( 515000 8111667 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"BluetoothProfileState:0" prio=5 tid=33 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x416108e0 self=0xd5ea20
  | sysTid=428 nice=0 sched=0/0 cgrp=default handle=14020208
  | schedstat=( 433334 5621666 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"BluetoothProfileState:1" prio=5 tid=32 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x418e6c68 self=0xd495e8
  | sysTid=427 nice=0 sched=0/0 cgrp=default handle=13933112
  | schedstat=( 548335 1224999 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"BluetoothProfileState:2" prio=5 tid=31 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411d50c8 self=0xd4bbe8
  | sysTid=417 nice=0 sched=0/0 cgrp=default handle=13942840
  | schedstat=( 531666 2350000 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"InputDispatcher" prio=10 tid=30 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x419cc238 self=0xd49bb0
  | sysTid=415 nice=-8 sched=0/0 cgrp=default handle=13921312
  | schedstat=( 125730451221 24602961699 948809 ) utm=6568 stm=6005 core=0
  at dalvik.system.NativeStart.run(Native Method)

"InputReader" prio=10 tid=29 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x419cc160 self=0xd48330
  | sysTid=416 nice=-8 sched=0/0 cgrp=default handle=13921400
  | schedstat=( 646270001 85808327 1896 ) utm=42 stm=22 core=0
  at dalvik.system.NativeStart.run(Native Method)

"android.hardware.SensorManager$SensorThread" prio=5 tid=28 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a14bf0 self=0xd461b8
  | sysTid=414 nice=-8 sched=0/0 cgrp=default handle=13919752
  | schedstat=( 9999583359 1322735004 56049 ) utm=999 stm=0 core=0
  at android.hardware.SensorManager.sensors_data_poll(Native Method)
  at android.hardware.SensorManager$SensorThread$SensorThreadRunnable.run(SensorManager.java:500)
  at java.lang.Thread.run(Thread.java:856)

"SoundPool" prio=5 tid=27 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41177170 self=0xd45648
  | sysTid=412 nice=0 sched=0/0 cgrp=default handle=13907016
  | schedstat=( 486668 12768332 3 ) utm=0 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"SoundPoolThread" prio=5 tid=26 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x419c7a40 self=0xd43598
  | sysTid=413 nice=0 sched=0/0 cgrp=default handle=13907232
  | schedstat=( 2259998 16940000 13 ) utm=0 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"WindowManagerPolicy" prio=5 tid=25 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x412d8c08 self=0xd42800
  | sysTid=411 nice=-2 sched=0/0 cgrp=default handle=13891392
  | schedstat=( 56818053305 138701194894 463324 ) utm=3070 stm=2611 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at com.android.server.wm.WindowManagerService$PolicyThread.run(WindowManagerService.java:753)

"WindowManager" prio=5 tid=24 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x412f0460 self=0xd3e630
  | sysTid=410 nice=-4 sched=0/0 cgrp=default handle=13888128
  | schedstat=( 859112673953 552302440811 1691113 ) utm=74809 stm=11102 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at com.android.server.wm.WindowManagerService$WMThread.run(WindowManagerService.java:711)

"AlarmManager" prio=5 tid=23 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x41a0f208 self=0xd3d330
  | sysTid=409 nice=0 sched=0/0 cgrp=default handle=13883264
  | schedstat=( 329415625510 885121090773 1056592 ) utm=24289 stm=8652 core=0
  at com.android.server.am.PendingIntentRecord.sendInner(PendingIntentRecord.java:~190)
  - waiting to lock <0x411444a8> (a com.android.server.am.ActivityManagerService) held by tid=64 (Binder Thread #4)
  at com.android.server.am.PendingIntentRecord.send(PendingIntentRecord.java:182)
  at android.app.PendingIntent.send(PendingIntent.java:509)
  at android.app.PendingIntent.send(PendingIntent.java:463)
  at com.android.server.AlarmManagerService$AlarmThread.run(AlarmManagerService.java:689)

"PowerManagerService" prio=5 tid=22 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4164bfe8 self=0xd3c060
  | sysTid=408 nice=0 sched=0/0 cgrp=default handle=13878448
  | schedstat=( 8655426609 23317923365 49933 ) utm=509 stm=356 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"PowerManagerService.mScreenOffThread" prio=5 tid=21 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4157b5a8 self=0xd3b898
  | sysTid=407 nice=0 sched=0/0 cgrp=default handle=13861096
  | schedstat=( 11301667 14313333 43 ) utm=0 stm=1 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"UEventObserver" prio=5 tid=19 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x414469b0 self=0xd22a88
  | sysTid=405 nice=0 sched=0/0 cgrp=default handle=13843744
  | schedstat=( 1508103317 5160125010 3584 ) utm=96 stm=54 core=0
  at android.os.UEventObserver.next_event(Native Method)
  at android.os.UEventObserver.access$100(UEventObserver.java:39)
  at android.os.UEventObserver$UEventThread.run(UEventObserver.java:102)

"SyncHandlerThread" prio=5 tid=18 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x419dac50 self=0xd002c8
  | sysTid=402 nice=10 sched=0/0 cgrp=bg_non_interactive handle=13631056
  | schedstat=( 1542998281 198183923361 4990 ) utm=89 stm=65 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"AccountManagerService" prio=5 tid=17 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41a2b378 self=0xc8fb10
  | sysTid=401 nice=0 sched=0/0 cgrp=default handle=13172576
  | schedstat=( 583335 4178332 6 ) utm=0 stm=0 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"FileObserver" prio=5 tid=16 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4116b048 self=0xbdcca0
  | sysTid=385 nice=0 sched=0/0 cgrp=default handle=12282312
  | schedstat=( 1546866684 5969376673 15754 ) utm=84 stm=70 core=0
  at android.os.FileObserver$ObserverThread.observe(Native Method)
  at android.os.FileObserver$ObserverThread.run(FileObserver.java:88)

"PackageManager" prio=5 tid=14 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x41193f10 self=0xbdaf60
  | sysTid=332 nice=10 sched=0/0 cgrp=bg_non_interactive handle=12450680
  | schedstat=( 69329380251 512090131337 394753 ) utm=5660 stm=1272 core=0
  at android.os.MessageQueue.nativePollOnce(Native Method)
  at android.os.MessageQueue.next(MessageQueue.java:118)
  at android.os.Looper.loop(Looper.java:118)
  at android.os.HandlerThread.run(HandlerThread.java:60)

"ProcessStats" prio=5 tid=15 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4118e948 self=0xbdec78
  | sysTid=331 nice=0 sched=0/0 cgrp=default handle=12447944
  | schedstat=( 90798525092 32491228232 157548 ) utm=272 stm=8807 core=0
  at libcore.io.Posix.readBytes(Native Method)
  at libcore.io.Posix.read(Posix.java:118)
  at libcore.io.BlockGuardOs.read(BlockGuardOs.java:149)
  at libcore.io.IoBridge.read(IoBridge.java:422)
  at java.io.FileInputStream.read(FileInputStream.java:179)
  at java.io.InputStream.read(InputStream.java:163)
  at com.android.internal.os.BatteryStatsImpl.readKernelWakelockStats(BatteryStatsImpl.java:1034)
  at com.android.internal.os.BatteryStatsImpl.updateKernelWakelocksLocked(BatteryStatsImpl.java:4436)
  at com.android.internal.os.BatteryStatsImpl.writeSummaryToParcel(BatteryStatsImpl.java:5240)
  at com.android.internal.os.BatteryStatsImpl.writeLocked(BatteryStatsImpl.java:4836)
  at com.android.internal.os.BatteryStatsImpl.writeAsyncLocked(BatteryStatsImpl.java:4818)
  at com.android.server.am.ActivityManagerService.updateCpuStatsNow(ActivityManagerService.java:1709)
  at com.android.server.am.ActivityManagerService$3.run(ActivityManagerService.java:1591)

"ActivityManager" prio=5 tid=13 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x411442b0 self=0xc71b78
  | sysTid=329 nice=-2 sched=0/0 cgrp=default handle=13047920
  | schedstat=( 630155046054 625389780218 655421 ) utm=31265 stm=31750 core=0
  at com.android.server.am.ActivityManagerService.updateCpuStatsNow(ActivityManagerService.java:~1629)
  - waiting to lock <0x4118e948> (a com.android.server.am.ActivityManagerService$3) held by tid=15 (ProcessStats)
  at com.android.server.am.ActivityManagerService.batteryNeedsCpuUpdate(ActivityManagerService.java:1717)
  at com.android.internal.os.BatteryStatsImpl$MyHandler.handleMessage(BatteryStatsImpl.java:127)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.am.ActivityManagerService$AThread.run(ActivityManagerService.java:1471)

"SensorService" prio=10 tid=12 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411356e8 self=0xc70fc0
  | sysTid=327 nice=-8 sched=0/0 cgrp=default handle=13043696
  | schedstat=( 31380386723 1408578578 113991 ) utm=0 stm=3138 core=0
  at dalvik.system.NativeStart.run(Native Method)

"android.server.ServerThread" prio=5 tid=11 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x411353e0 self=0xc70830
  | sysTid=328 nice=-2 sched=0/0 cgrp=default handle=13044864
  | schedstat=( 672092076415 384759458048 843615 ) utm=37328 stm=29881 core=0
  at com.android.server.am.ActivityManagerService.monitor(ActivityManagerService.java:~15259)
  - waiting to lock <0x411444a8> (a com.android.server.am.ActivityManagerService) held by tid=64 (Binder Thread #4)
  at com.android.server.Watchdog$HeartbeatHandler.handleMessage(Watchdog.java:137)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.ServerThread.run(SystemServer.java:791)

"Binder Thread #2" prio=5 tid=10 SUSPENDED
  | group="main" sCount=1 dsCount=0 obj=0x41131a48 self=0xc67d08
  | sysTid=326 nice=0 sched=0/0 cgrp=default handle=12982520
  | schedstat=( 160901096908 249119233320 465447 ) utm=12681 stm=3409 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Binder Thread #1" prio=5 tid=9 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x411318f0 self=0xc674a0
  | sysTid=325 nice=0 sched=0/0 cgrp=default handle=12999256
  | schedstat=( 156911344981 251604124892 467608 ) utm=12368 stm=3323 core=0
  at dalvik.system.NativeStart.run(Native Method)

"FinalizerWatchdogDaemon" daemon prio=5 tid=8 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4112d858 self=0xc66e48
  | sysTid=324 nice=0 sched=0/0 cgrp=default handle=12980128
  | schedstat=( 659731603 5725435008 9274 ) utm=33 stm=32 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40af3328> (a java.lang.Daemons$FinalizerWatchdogDaemon)
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$FinalizerWatchdogDaemon.run(Daemons.java:216)
  at java.lang.Thread.run(Thread.java:856)

"FinalizerDaemon" daemon prio=5 tid=7 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4112d700 self=0xc669f8
  | sysTid=323 nice=0 sched=0/0 cgrp=default handle=13001176
  | schedstat=( 39252596678 75532495024 230095 ) utm=3131 stm=794 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40ae15d0> (a java.lang.ref.ReferenceQueue)
  at java.lang.Object.wait(Object.java:401)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:102)
  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:73)
  at java.lang.Daemons$FinalizerDaemon.run(Daemons.java:168)
  at java.lang.Thread.run(Thread.java:856)

"ReferenceQueueDaemon" daemon prio=5 tid=6 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x4112d598 self=0xc665a8
  | sysTid=322 nice=0 sched=0/0 cgrp=default handle=12995392
  | schedstat=( 3604643442 600466660 18538 ) utm=301 stm=59 core=0
  at java.lang.Object.wait(Native Method)
  - waiting on <0x40ae14f8> 
  at java.lang.Object.wait(Object.java:364)
  at java.lang.Daemons$ReferenceQueueDaemon.run(Daemons.java:128)
  at java.lang.Thread.run(Thread.java:856)

"Compiler" daemon prio=5 tid=5 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4112d4a8 self=0xba4778
  | sysTid=321 nice=0 sched=0/0 cgrp=default handle=12221136
  | schedstat=( 224053766961 262856655154 990037 ) utm=13828 stm=8577 core=0
  at dalvik.system.NativeStart.run(Native Method)

"JDWP" daemon prio=5 tid=4 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4112d3c0 self=0xc646f0
  | sysTid=320 nice=0 sched=0/0 cgrp=default handle=12217408
  | schedstat=( 470000 558333 7 ) utm=0 stm=0 core=0
  at dalvik.system.NativeStart.run(Native Method)

"Signal Catcher" daemon prio=5 tid=3 RUNNABLE
  | group="system" sCount=0 dsCount=0 obj=0x4112d2c8 self=0xba6278
  | sysTid=319 nice=0 sched=0/0 cgrp=default handle=12217240
  | schedstat=( 561398340 369503338 7307 ) utm=6 stm=50 core=0
  at dalvik.system.NativeStart.run(Native Method)

"GC" daemon prio=5 tid=2 VMWAIT
  | group="system" sCount=1 dsCount=0 obj=0x4112d1e8 self=0xba4f00
  | sysTid=316 nice=0 sched=0/0 cgrp=default handle=12337880
  | schedstat=( 396796549922 475444031648 113822 ) utm=38853 stm=826 core=0
  at dalvik.system.NativeStart.run(Native Method)

----- end 314 -----


it can be seen that
ActivityManager(java tid=13) is waiting on lock held by "ProcessStats"(java tid=15 ) which is blocking on io read.
“ProcessStats” is held the lock to do “IO” operation in kernel, but it’s cost too much time that lead to “watchdog” unhappy.

"ActivityManager" prio=5 tid=13 MONITOR
  | group="main" sCount=1 dsCount=0 obj=0x411442b0 self=0xc71b78
  | sysTid=329 nice=-2 sched=0/0 cgrp=default handle=13047920
  | schedstat=( 630155046054 625389780218 655421 ) utm=31265 stm=31750 core=0
  at com.android.server.am.ActivityManagerService.updateCpuStatsNow(ActivityManagerService.java:~1629)
  - waiting to lock <0x4118e948> (a com.android.server.am.ActivityManagerService$3) held by tid=15 (ProcessStats)
  at com.android.server.am.ActivityManagerService.batteryNeedsCpuUpdate(ActivityManagerService.java:1717)
  at com.android.internal.os.BatteryStatsImpl$MyHandler.handleMessage(BatteryStatsImpl.java:127)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:137)
  at com.android.server.am.ActivityManagerService$AThread.run(ActivityManagerService.java:1471)

"ProcessStats" prio=5 tid=15 NATIVE
  | group="main" sCount=1 dsCount=0 obj=0x4118e948 self=0xbdec78
  | sysTid=331 nice=0 sched=0/0 cgrp=default handle=12447944
  | schedstat=( 90798525092 32491228232 157548 ) utm=272 stm=8807 core=0
  at libcore.io.Posix.readBytes(Native Method)
  at libcore.io.Posix.read(Posix.java:118)
  at libcore.io.BlockGuardOs.read(BlockGuardOs.java:149)
  at libcore.io.IoBridge.read(IoBridge.java:422)
  at java.io.FileInputStream.read(FileInputStream.java:179)
  at java.io.InputStream.read(InputStream.java:163)
  at com.android.internal.os.BatteryStatsImpl.readKernelWakelockStats(BatteryStatsImpl.java:1034)
  at com.android.internal.os.BatteryStatsImpl.updateKernelWakelocksLocked(BatteryStatsImpl.java:4436)
  at com.android.internal.os.BatteryStatsImpl.writeSummaryToParcel(BatteryStatsImpl.java:5240)
  at com.android.internal.os.BatteryStatsImpl.writeLocked(BatteryStatsImpl.java:4836)
  at com.android.internal.os.BatteryStatsImpl.writeAsyncLocked(BatteryStatsImpl.java:4818)
  at com.android.server.am.ActivityManagerService.updateCpuStatsNow(ActivityManagerService.java:1709)
  at com.android.server.am.ActivityManagerService$3.run(ActivityManagerService.java:1591)

[More about watchdog]
The watchdog mechanism.
Watchdog is implemented in watchdog.java
53 /** This class calls its monitor every minute. Killing this process if they don't return **/
54 public class Watchdog extends Thread { }

The system services register to watchdog to be polled.
Watchdog.getInstance().addMonitor(service);

Watchdog is started as a thread in SystemServer.java

225            Slog.i(TAG, "Init Watchdog");
226            Watchdog.getInstance().init(context, battery, power, alarm,
227                    ActivityManagerService.self());

737                Watchdog.getInstance().start();

Watchdog check the services periodically. and if one service blocked for a long time, watchdog kill the service and dump it.
Because process scheduling and latency, the dump message may be not logged completely.

[More about Looper]
More about message handler/looper, and SystemServer.java
SystemServer::init1 for native services;
SystemServer::init2 for java services in system_server;

In init2, ServerThread "android.server.ServerThread" is created, and Looper.prepare(), and initialize, and Looper.loop().
87         Looper.prepare();


225            Slog.i(TAG, "Init Watchdog");
226            Watchdog.getInstance().init(context, battery, power, alarm,
227                    ActivityManagerService.self());

687        ActivityManagerService.self().systemReady(new Runnable() {
688            public void run() {

737                Watchdog.getInstance().start();

    }

790        Looper.loop();
791        Slog.d(TAG, "System ServerThread is exiting!");
792    }
  
So, Watchdog thread sends MONITOR message peridically to ServerThread message queue(looper) to loop and dispath.
At last, the ServerThread is only handleMessage(Watchdog.MONITOR) to monitor() {synchronized(ObjectInService);} the services.

Now, the root cause in user space is that ProcessStats. 
Closely look at, BatteryStatsImpl::readKernelWakelockStats, wake lock again!!!
The last thing, why Wakelock read wastes so much time?

The crash is caused by the wake lock of power manager, and the crash happened when reading "/proc/wakelocks" by the method "readKernelWakelockStats()".
It is a buffer overflow issue.
QUALCOMM suggest increase the /proc/sys/vm/min_free_bytes to 8192 and try test again

[Conclusion]

[Issue Description]
Step by Step:
1.Size of /proc/wakelocks is larger than 4096 byte.
2.USB connect and remove.

[Reason]
If size of /proc/wakelocks is larger than local buffer of BatteryStatsImpl#readKernelWakelockStats,
occur buffer over run in BatteryStatsImpl#parseProcWakelocks.
The cause of the problem was the disconnection of the charger, altering the status of the battery.

[Modified Source]
~/frameworks/base/core/java/com/android/internal/os/BatteryStatsImpl.java

[Modified function]
BatteryStatsImpl#readKernelWakelockStats
BatteryStatsImpl#parseProcWakelocks

[Solution]
If size of /proc/wakelocks is larger than 4096 byte,
BatteryStatsImpl#readKernelWakelockStats return null.
Modify buffer over run in BatteryStatsImpl#parseProcWakelocks.

byte[] buffer = new byte[4096];
int len;

try {
FileInputStream is = new FileInputStream("/proc/wakelocks");
len = is.read(buffer);
is.close(); ...


[Effected Area]
When charger event occur.

Has confirmed the following.
- Size of /proc/wakelocks is larger than 4096 byte. And USB connect and remove.

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值