Android 信号处理面面观 之 trace 文件含义
2016-04-07 22:43
239 查看
在前一章Android 信号处理面面观 之 信号定义、行为和来源 中,我们讨论过,Android
应用在收到异常终止信号(SIGQUIT)时,没有遵循传统 UNIX信号模型的默认行为 (终止 + core )。而是打印出trace 文件来,以利于记录应用异常终止的原因。 本文就重点分析 trace 文件是怎么产生的,并详细解释trace文件的各个字段的含义。
一. TRACE 文件的产生
Trace文件是 android davik 虚拟机在收到异常终止信号 (SIGQUIT)时产生的。 最经常的触发条件是 android应用中产生了 FC (force close)。由于是该文件的产生是在 DVM里,所以只有运行 dvm实例的进程(如普通的java应用,java服务等)才会产生该文件,android 本地应用 (native app,指 运行在 android lib层,用c/c++编写的linux应用、库、服务等)在收到 SIGQUIT时是不会产生 trace文件的。
如上文Android 信号处理面面观 之 信号定义、行为和来源所述,我们可以在终端通过adb发送SIGQUIT给应用来生成trace文件。
dalvik/vm/init.h [.c]
davik/vm/SignalCatcher.h[.c]
dalvik/vm/Thread.h[.c]
Android ICS 实现文件后缀是 .cpp。
实现过程分以下几步:
Step #1: DVM初始化时,设置信号屏蔽字,屏蔽要特殊处理的信号(SIGQUIT, SIGUSR1, SIGUSR2)。由于信号处理方式是进程范围起作用的, 这意味着该进程里所有的线程都将屏蔽该信号。 实现代码在init.c中如下:
blockSignals()的实现很简答,它是通过 sigprocmask() 函数调用实现的,代码在init.c如下:
Step #2: DVM 生成单独的信号处理线程,用来对三个信号做特殊处理 (init.c):
我们看到,DVM调用dvmCreateInternalThread()来生成一个新的内部线程 来专门处理dvm进程里的信号。 后面我们会看到,dvmCreateInternalThread()其实是使用pthread_create()来产生新的线程。 该线程的处理函数是 signalCatcherThreadStart()。 (dvm里所谓的 内部线程,就是用来帮助dvm实现本身使用的线程,比如
信号处理线程,binder线程,Compiler线程,JDWP线程等,而不是应用程序申请的线程。 在后面我们计划用专门的一章来讨论DVM线程模式)
signalCatcherThreadStart() 实现框架如下:
至此我们已经能够看到,dvm对三个信号分别所做的特殊用途:
1. SIGUSR1 被用来 做手工垃圾收集。处理函数是 HandleSigUsr1()
2. SIGUSR2 被用来做 JIT的调试。如果JIT下编译时打开,收到SIGUSR2是dvm会dump出相关的调试信息。处理逻辑如下:
由于以上两个信号都仅用于DVM的内部实现的调试,本文不作详细的分析。读者可以在终端通过adb发送 SIGUSR1 和SIGUSR2信号来观察它的行为。
3. SIGQUIT 用来 输出trace文件,以记录异常终止是dvm的上下文信息.
SIGQUIT的处理函数如下所示:
它首先查看有木有指定 trace输出文件,没有就将trace信息打印到log里。如果有,就先将trace信息打印到内存文件中,然后再讲改内存文件内容输出到指定trace文件中。
有些读者肯能觉得奇怪,为什么指定了trace文件后,不直接打印trace信息到trace文件中呢。 原因是 trace文件实际上记录的是当前运行的所有的线程的上下文信息。他需要 暂停所有的线程才能输出。 dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP);的调用正式这个目的。可以看出,这个操作代价是很高的,它把当前所有的线程都停了下来。执行的时间越短,对正常运行的线程的影响越小。 输出信息到内存比直接到外部文件要快得多。所以 dvm采取了先输出到内存,马上恢复线程程,然后就可以慢慢的输出到外部文件里了。
而这真正的输出信息实现在 logThreadStacks()中:
它的输出格式如下:
至此, 我们可以很清楚的 解析 trace文件中 thread信息的含义了:
1. 第一行是 固定的头, 指明下面的都是 当前运行的 dvm thread :“DALVIK THREADS:”
2. 第二行输出的是该 进程里各种线程互斥量的值。(具体的互斥量的作用在 dalvik 线程一章 单独陈述)
3. 第三行输出分别是 线程的名字(“main”),线程优先级(“prio=5”),线程id(“tid=1”) 以及线程的 类型(“NATIVE”)
4. 第四行分别是线程所述的线程组 (“main”),线程被正常挂起的次处(“sCount=1”),线程因调试而挂起次数(”dsCount=0“),当前线程所关联的java线程对象(”obj=0x400246a0“)以及该线程本身的地址(“self=0x12770”)。
5. 第五行 显示 线程调度信息。 分别是该线程在linux系统下得本地线程id (“ sysTid=503”),线程的调度有优先级(“nice=0”),调度策略(sched=0/0),优先组属(“cgrp=default”)以及 处理函数地址(“handle=-1342909272”)
6 第六行 显示更多该线程当前上下文,分别是 调度状态(从 /proc/[pid]/task/[tid]/schedstat读出)(“schedstat=( 15165039025 12197235258 23068 )”),以及该线程运行信息 ,它们是 线程用户态下使用的时间值(单位是jiffies)(“utm=182”), 内核态下得调度时间值(“stm=1334”),以及最后运行改线程的cup标识(“core=0”);
7.后面几行输出 该线程 调用栈。
有了以上信息,我们便更容易分析出app是为什么被异常终止的了。我们会在单独的一章分析, 怎样利用trace文件里的信息寻找app异常终止的原因。敬请期待。
应用在收到异常终止信号(SIGQUIT)时,没有遵循传统 UNIX信号模型的默认行为 (终止 + core )。而是打印出trace 文件来,以利于记录应用异常终止的原因。 本文就重点分析 trace 文件是怎么产生的,并详细解释trace文件的各个字段的含义。
一. TRACE 文件的产生
Trace文件是 android davik 虚拟机在收到异常终止信号 (SIGQUIT)时产生的。 最经常的触发条件是 android应用中产生了 FC (force close)。由于是该文件的产生是在 DVM里,所以只有运行 dvm实例的进程(如普通的java应用,java服务等)才会产生该文件,android 本地应用 (native app,指 运行在 android lib层,用c/c++编写的linux应用、库、服务等)在收到 SIGQUIT时是不会产生 trace文件的。如上文Android 信号处理面面观 之 信号定义、行为和来源所述,我们可以在终端通过adb发送SIGQUIT给应用来生成trace文件。
二. TRACE文件的实现
相关实现在以下几个文件中:dalvik/vm/init.h [.c]
davik/vm/SignalCatcher.h[.c]
dalvik/vm/Thread.h[.c]
Android ICS 实现文件后缀是 .cpp。
实现过程分以下几步:
Step #1: DVM初始化时,设置信号屏蔽字,屏蔽要特殊处理的信号(SIGQUIT, SIGUSR1, SIGUSR2)。由于信号处理方式是进程范围起作用的, 这意味着该进程里所有的线程都将屏蔽该信号。 实现代码在init.c中如下:
int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized, JNIEnv* pEnv) { ... /* configure signal handling */ if (!gDvm.reduceSignals) blockSignals(); ... }
blockSignals()的实现很简答,它是通过 sigprocmask() 函数调用实现的,代码在init.c如下:
/* * Configure signals. We need to block SIGQUIT so that the signal only * reaches the dump-stack-trace thread. * * This can be disabled with the "-Xrs" flag. */ static void blockSignals() { sigset_t mask; int cc; sigemptyset(&mask); sigaddset(&mask, SIGQUIT); sigaddset(&mask, SIGUSR1); // used to initiate heap dump #if defined(WITH_JIT) && defined(WITH_JIT_TUNING) sigaddset(&mask, SIGUSR2); // used to investigate JIT internals #endif //sigaddset(&mask, SIGPIPE); cc = sigprocmask(SIG_BLOCK, &mask, NULL); assert(cc == 0); }
Step #2: DVM 生成单独的信号处理线程,用来对三个信号做特殊处理 (init.c):
/* * Do non-zygote-mode initialization. This is done during VM init for * standard startup, or after a "zygote fork" when creating a new process. */ bool dvmInitAfterZygote(void) { ... /* start signal catcher thread that dumps stacks on SIGQUIT */ if (!gDvm.reduceSignals && !gDvm.noQuitHandler) { if (!dvmSignalCatcherStartup()) return false; } ... }dvmSignalCatcherStartup() 实现在 SignalCatcher.c 中:
/* * Crank up the signal catcher thread. * * Returns immediately. */ bool dvmSignalCatcherStartup(void) { gDvm.haltSignalCatcher = false; if (!dvmCreateInternalThread(&gDvm.signalCatcherHandle, "Signal Catcher", signalCatcherThreadStart, NULL)) return false; return true; }
我们看到,DVM调用dvmCreateInternalThread()来生成一个新的内部线程 来专门处理dvm进程里的信号。 后面我们会看到,dvmCreateInternalThread()其实是使用pthread_create()来产生新的线程。 该线程的处理函数是 signalCatcherThreadStart()。 (dvm里所谓的 内部线程,就是用来帮助dvm实现本身使用的线程,比如
信号处理线程,binder线程,Compiler线程,JDWP线程等,而不是应用程序申请的线程。 在后面我们计划用专门的一章来讨论DVM线程模式)
signalCatcherThreadStart() 实现框架如下:
/* * Sleep in sigwait() until a signal arrives. */ static void* signalCatcherThreadStart(void* arg) { ... /* set up mask with signals we want to handle */ sigemptyset(&mask); sigaddset(&mask, SIGQUIT); sigaddset(&mask, SIGUSR1); #if defined(WITH_JIT) && defined(WITH_JIT_TUNING) sigaddset(&mask, SIGUSR2); #endif ... while (true) { ... loop: cc = sigwait(&mask, &rcvd); ... switch (rcvd) { case SIGQUIT: handleSigQuit(); break; case SIGUSR1: handleSigUsr1(); break; #if defined(WITH_JIT) && defined(WITH_JIT_TUNING) case SIGUSR2: handleSigUsr2(); break; #endif ... }它首先设置我们要处理的信号集(SIGQUIT, SIGUSR1, SIGUSR2), 然后 调用 sigwait()。 我们知道sigwait()会在当前的线程里 重新 打开 指定的信号屏蔽字屏蔽的信号集。 在刚才的分析中,我们看到,dvm在启动时,首先在整个进程里设置信号屏蔽字屏蔽掉三个信号,sigwait()的调用,使的这三个信号只在 SignalCatcher线程里响应。
至此我们已经能够看到,dvm对三个信号分别所做的特殊用途:
1. SIGUSR1 被用来 做手工垃圾收集。处理函数是 HandleSigUsr1()
static void handleSigUsr1(void) { LOGI("SIGUSR1 forcing GC (no HPROF)\n"); dvmCollectGarbage(false); }
2. SIGUSR2 被用来做 JIT的调试。如果JIT下编译时打开,收到SIGUSR2是dvm会dump出相关的调试信息。处理逻辑如下:
#if defined(WITH_JIT) && defined(WITH_JIT_TUNING) /* * Respond to a SIGUSR2 by dumping some JIT stats and possibly resetting * the code cache. */ static void handleSigUsr2(void) { static int codeCacheResetCount = 0; if ((--codeCacheResetCount & 7) == 0) { gDvmJit.codeCacheFull = true; } else { dvmCompilerDumpStats(); /* Stress-test unchain all */ dvmJitUnchainAll(); LOGD("Send %d more signals to rest the code cache", codeCacheResetCount & 7); } } #endif
由于以上两个信号都仅用于DVM的内部实现的调试,本文不作详细的分析。读者可以在终端通过adb发送 SIGUSR1 和SIGUSR2信号来观察它的行为。
3. SIGQUIT 用来 输出trace文件,以记录异常终止是dvm的上下文信息.
SIGQUIT的处理函数如下所示:
static void handleSigQuit(void) { ... dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP); if (gDvm.stackTraceFile == NULL) { /* just dump to log */ DebugOutputTarget target; dvmCreateLogOutputTarget(&target, ANDROID_LOG_INFO, LOG_TAG); dvmDumpAllThreadsEx(&target, true); } else { /* write to memory buffer */ FILE* memfp = open_memstream(&traceBuf, &traceLen); if (memfp == NULL) { LOGE("Unable to create memstream for stack traces\n"); traceBuf = NULL; /* make sure it didn't touch this */ /* continue on */ } else { logThreadStacks(memfp); fclose(memfp); } } #if defined(WITH_JIT) && defined(WITH_JIT_TUNING) dvmCompilerDumpStats(); #endif dvmResumeAllThreads(SUSPEND_FOR_STACK_DUMP); if (traceBuf != NULL) { int fd = open(gDvm.stackTraceFile, O_WRONLY | O_APPEND | O_CREAT, 0666); if (fd < 0) { LOGE("Unable to open stack trace file '%s': %s\n", gDvm.stackTraceFile, strerror(errno)); } else { ... } ... }
它首先查看有木有指定 trace输出文件,没有就将trace信息打印到log里。如果有,就先将trace信息打印到内存文件中,然后再讲改内存文件内容输出到指定trace文件中。
有些读者肯能觉得奇怪,为什么指定了trace文件后,不直接打印trace信息到trace文件中呢。 原因是 trace文件实际上记录的是当前运行的所有的线程的上下文信息。他需要 暂停所有的线程才能输出。 dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP);的调用正式这个目的。可以看出,这个操作代价是很高的,它把当前所有的线程都停了下来。执行的时间越短,对正常运行的线程的影响越小。 输出信息到内存比直接到外部文件要快得多。所以 dvm采取了先输出到内存,马上恢复线程程,然后就可以慢慢的输出到外部文件里了。
而这真正的输出信息实现在 logThreadStacks()中:
static void logThreadStacks(FILE* fp) { dvmPrintDebugMessage(&target, "\n\n----- pid %d at %04d-%02d-%02d %02d:%02d:%02d -----\n", pid, ptm->tm_year + 1900, ptm->tm_mon+1, ptm->tm_mday, ptm->tm_hour, ptm->tm_min, ptm->tm_sec); printProcessName(&target); dvmPrintDebugMessage(&target, "\n"); dvmDumpAllThreadsEx(&target, true); fprintf(fp, "----- end %d -----\n", pid); }该函数打印了trace文件的框架,其输出类似如下所示:
----- pid 503 at 2011-11-21 21:59:12 ----- Cmd line: com.android.phone <Thread_info> ----- end 503 -----它显示当前dvm进程的进程id,名字,输出的时间。最重要的所有线程的上下文信息是有函数 dvmDumpAllThreadsEx()里实现的,该函数定义在 thread.c里:
void dvmDumpAllThreadsEx(const DebugOutputTarget* target, bool grabLock) { Thread* thread; dvmPrintDebugMessage(target, "DALVIK THREADS:\n"); #ifdef HAVE_ANDROID_OS dvmPrintDebugMessage(target, "(mutexes: tll=%x tsl=%x tscl=%x ghl=%x hwl=%x hwll=%x)\n", gDvm.threadListLock.value, gDvm._threadSuspendLock.value, gDvm.threadSuspendCountLock.value, gDvm.gcHeapLock.value, gDvm.heapWorkerLock.value, gDvm.heapWorkerListLock.value); #endif if (grabLock) dvmLockThreadList(dvmThreadSelf()); thread = gDvm.threadList; while (thread != NULL) { dvmDumpThreadEx(target, thread, false); /* verify link */ assert(thread->next == NULL || thread->next->prev == thread); thread = thread->next; } if (grabLock) dvmUnlockThreadList(); }
它的输出格式如下:
DALVIK THREADS: (mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0) "main" prio=5 tid=1 NATIVE | group="main" sCount=1 dsCount=0 obj=0x400246a0 self=0x12770 | sysTid=503 nice=0 sched=0/0 cgrp=default handle=-1342909272 | schedstat=( 15165039025 12197235258 23068 ) utm=182 stm=1334 core=0 at android.os.MessageQueue.nativePollOnce(Native Method) at android.os.MessageQueue.next(MessageQueue.java:119) at android.os.Looper.loop(Looper.java:122) at android.app.ActivityThread.main(ActivityThread.java:4134) at java.lang.reflect.Method.invokeNative(Native Method) at java.lang.reflect.Method.invoke(Method.java:491) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:841) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:599) at dalvik.system.NativeStart.main(Native Method)
至此, 我们可以很清楚的 解析 trace文件中 thread信息的含义了:
1. 第一行是 固定的头, 指明下面的都是 当前运行的 dvm thread :“DALVIK THREADS:”
2. 第二行输出的是该 进程里各种线程互斥量的值。(具体的互斥量的作用在 dalvik 线程一章 单独陈述)
3. 第三行输出分别是 线程的名字(“main”),线程优先级(“prio=5”),线程id(“tid=1”) 以及线程的 类型(“NATIVE”)
4. 第四行分别是线程所述的线程组 (“main”),线程被正常挂起的次处(“sCount=1”),线程因调试而挂起次数(”dsCount=0“),当前线程所关联的java线程对象(”obj=0x400246a0“)以及该线程本身的地址(“self=0x12770”)。
5. 第五行 显示 线程调度信息。 分别是该线程在linux系统下得本地线程id (“ sysTid=503”),线程的调度有优先级(“nice=0”),调度策略(sched=0/0),优先组属(“cgrp=default”)以及 处理函数地址(“handle=-1342909272”)
6 第六行 显示更多该线程当前上下文,分别是 调度状态(从 /proc/[pid]/task/[tid]/schedstat读出)(“schedstat=( 15165039025 12197235258 23068 )”),以及该线程运行信息 ,它们是 线程用户态下使用的时间值(单位是jiffies)(“utm=182”), 内核态下得调度时间值(“stm=1334”),以及最后运行改线程的cup标识(“core=0”);
7.后面几行输出 该线程 调用栈。
有了以上信息,我们便更容易分析出app是为什么被异常终止的了。我们会在单独的一章分析, 怎样利用trace文件里的信息寻找app异常终止的原因。敬请期待。
相关文章推荐
- android studio gradle 获取与更新
- Android 信号处理面面观 之 信号定义、行为和来源
- 一款Android拼图游戏
- Android 点击按钮时改变颜色
- Android 信号处理面面观 之 概述
- Android实现图片滚动控件,含页签功能,让你的应用像淘宝一样炫起来
- Android:inputType常用取值
- [转]Android Thread第二次Thread.start()报错的疑问
- 解决android子控件与父控件滑动冲突的问题
- Android:inputType常用取值
- Android 入门ListView 的基本使用,BaseAdapter的编写
- Android开发:最详细的 Toolbar 开发实践总结
- 【转】Android贪吃蛇源代码
- Running Android Lint错误
- Android QRCodeReaderView 和Camera API冲突
- 如何设置Android的AVD模拟器可以输入中文
- 关于intent.setFlags()的一些故事
- Android-通过Java代码来实现属性动画
- android工具库
- 自己实现android侧滑菜单