ART虚拟机之Trace原理(转)

一、概述

Android 6.0系统采用的art虚拟机,所有的Java进程都运行在art之上,当应用发生ANR(Application Not Response,其中最终的一个环节便是向目标进程发送信号SIGNAL_QUIT, 传统的linux则是终止程序并输出core;而对于Android进程来说当收到SIGQUIT时,Java层面的进程都是跑在虚拟机之上的,ART虚拟机会捕获该信号,并输出相应的traces信息保存到目录/data/anr/traces.txt。

当然也可以通过一条命令来获取指定进程的traces信息,例如输出pid=888的进程信息:

adb shell kill -3 888 //可指定进程pid

执行完该命令后traces信息的结果保存到文件/data/anr/traces.txt,如下:

//[见小节2.2]
----- pid 888 at 2016-11-11 22:22:22 -----
Cmd line: system_server
ABI: arm
Build type: optimized
//[见小节3.1]
Zygote loaded classes=4113 post zygote classes=3239
//[见小节3.2]
Intern table: 57550 strong; 9315 weak
//共加载16动态库 [见小节3.3]
JNI: CheckJNI is off; globals=2418 (plus 115 weak)
Libraries: /system/lib/libandroid.so /system/lib/libandroid_servers.so /system/lib/libaudioeffect_jni.so /system/lib/libcompiler_rt.so /system/lib/libjavacrypto.so /system/lib/libjnigraphics.so /system/lib/libmedia_jni.so /system/lib/librs_jni.so /system/lib/libsechook.so /system/lib/libshell_jni.so /system/lib/libsoundpool.so /system/lib/libwebviewchromium_loader.so /system/lib/libwifi-service.so /vendor/lib/libalarmservice_jni.so /vendor/lib/liblocationservice.so libjavacore.so (16)
//已分配堆内存大小40MB,其中29M已用,总分配207772个对象 [见小节3.4]
Heap: 27% free, 29MB/40MB; 307772 objects
... //省略GC相关信息

//当前进程总99个线程[见小节3.5]
DALVIK THREADS (99):
//主线程调用栈[见小节3.6]
"main" prio=5 tid=1 Native
  | group="main" sCount=1 dsCount=0 obj=0x75bd9fb0 self=0x5573d4f770
  | sysTid=12078 nice=-2 cgrp=default sched=0/0 handle=0x7fa75fafe8
  | state=S schedstat=( 5907843636 827600677 5112 ) utm=453 stm=137 core=0 HZ=100
  | stack=0x7fd64ef000-0x7fd64f1000 stackSize=8MB
  | held mutexes=
  //内核栈[见小节3.6.2]
  kernel: __switch_to+0x70/0x7c
  kernel: SyS_epoll_wait+0x2a0/0x324
  kernel: SyS_epoll_pwait+0xa4/0x120
  kernel: cpu_switch_to+0x48/0x4c
  native: #00 pc 0000000000069be4  /system/lib64/libc.so (__epoll_pwait+8)
  native: #01 pc 000000000001cca4  /system/lib64/libc.so (epoll_pwait+32)
  native: #02 pc 000000000001ad74  /system/lib64/libutils.so (_ZN7android6Looper9pollInnerEi+144)
  native: #03 pc 000000000001b154  /system/lib64/libutils.so (_ZN7android6Looper8pollOnceEiPiS1_PPv+80)
  native: #04 pc 00000000000d4bc0  /system/lib64/libandroid_runtime.so (_ZN7android18NativeMessageQueue8pollOnceEP7_JNIEnvP8_jobjecti+48)
  native: #05 pc 000000000000082c  /data/dalvik-cache/arm64/system@framework@boot.oat (Java_android_os_MessageQueue_nativePollOnce__JI+144)
  at android.os.MessageQueue.nativePollOnce(Native method)
  at android.os.MessageQueue.next(MessageQueue.java:323)
  at android.os.Looper.loop(Looper.java:135)
  at com.android.server.SystemServer.run(SystemServer.java:290)
  at com.android.server.SystemServer.main(SystemServer.java:175)
  at java.lang.reflect.Method.invoke!(Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:738)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:628)
  
"Binder_1" prio=5 tid=8 Native
  | group="main" sCount=1 dsCount=0 obj=0x12c610a0 self=0x5573e5c750
  | sysTid=12092 nice=0 cgrp=default sched=0/0 handle=0x7fa2743450
  | state=S schedstat=( 796240075 863170759 3586 ) utm=50 stm=29 core=1 HZ=100
  | stack=0x7fa2647000-0x7fa2649000 stackSize=1013KB
  | held mutexes=
  kernel: __switch_to+0x70/0x7c
  kernel: binder_thread_read+0xd78/0xeb0
  kernel: binder_ioctl_write_read+0x178/0x24c
  kernel: binder_ioctl+0x2b0/0x5e0
  kernel: do_vfs_ioctl+0x4a4/0x578
  kernel: SyS_ioctl+0x5c/0x88
  kernel: cpu_switch_to+0x48/0x4c
  native: #00 pc 0000000000069cd0  /system/lib64/libc.so (__ioctl+4)
  native: #01 pc 0000000000073cf4  /system/lib64/libc.so (ioctl+100)
  native: #02 pc 000000000002d6e8  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+164)
  native: #03 pc 000000000002df3c  /system/lib64/libbinder.so (_ZN7android14IPCThreadState20getAndExecuteCommandEv+24)
  native: #04 pc 000000000002e114  /system/lib64/libbinder.so (_ZN7android14IPCThreadState14joinThreadPoolEb+124)
  native: #05 pc 0000000000036c38  /system/lib64/libbinder.so (???)
  native: #06 pc 000000000001579c  /system/lib64/libutils.so (_ZN7android6Thread11_threadLoopEPv+208)
  native: #07 pc 0000000000090598  /system/lib64/libandroid_runtime.so (_ZN7android14AndroidRuntime15javaThreadShellEPv+96)
  native: #08 pc 0000000000014fec  /system/lib64/libutils.so (???)
  native: #09 pc 0000000000067754  /system/lib64/libc.so (_ZL15__pthread_startPv+52)
  native: #10 pc 000000000001c644  /system/lib64/libc.so (__start_thread+16)
  (no managed stack frames)
... //此处省略剩余的N个线程.

 

实例:

"Binder_1" prio=5 tid=8 Native
  | group="main" sCount=1 dsCount=0 obj=0x12c610a0 self=0x5573e5c750
  | sysTid=12092 nice=0 cgrp=default sched=0/0 handle=0x7fa2743450
  | state=S schedstat=( 796240075 863170759 3586 ) utm=50 stm=29 core=1 HZ=100
  | stack=0x7fa2647000-0x7fa2649000 stackSize=1013KB
  | held mutexes=

解释:

  1. 第一行:线程名(“Binder_1”)(如果带有daemon说明是守护线程,线程优先级(“prio=5”),线程内部id(“tid=8”),线程状态(“NATIVE”)。
  2. 第二行: 线程所属的线程组 (“main”),线程挂起次数(“sCount=1”),用于调试的线程挂起次数(”dsCount=0“), 当前线程关联的java线程对象(”obj=0x12c610a0“),该线程地址(“self=0x5573e5c750”)。
  3. 第三行:线程真正意义上的tid(“sysTid=12092”),调度有优先级(“nice=0”), 优先组属(“cgrp=default”),调度策略(sched=0/0), 处理函数地址(“handle=0x7fa2743450”)
  4. 第四行: 线程状态(S), 调度时间统计schedstat,线程用户态下使用的时间值(单位是jiffies)(“utm=50”), 内核态下得调度时间值(“stm=20”),最后运行该线程的核(“core=1”)
  5. 第五行:线程栈的地址区间(“0x7fa2647000-0x7fa2649000”),以及栈的大小(“1013KB”)
  6. 第六行:所持有的mutex类型,有独占锁exclusive和共享锁shared两类。

说明:

  • CPU调度统计信息(schedstat):通过读取节点/proc/[pid]/task/[tid]/schedstat
  • CPU使用统计:通过读取节点/proc/self/task/[tid]/stat
  • 内核栈:通过读取节点/proc/self/task/[tid]/stack
  • jiffies系统的节拍数,该值是1/HZ,一般来说100HZ,也就意味着1jiffies = 10ms.
  • 线程状态:除了Native,另外还有Running, Blocked等状态,进程没有依附的状态(not attached)

 

转自:http://gityuan.com/2016/11/26/art-trace/

posted @ 2017-05-18 16:36  鸭子船长  阅读(1103)  评论(0编辑  收藏  举报