在前一章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文件。

 

二. 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中如下：

  1. int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,  
  2.     JNIEnv* pEnv)  
  3. {  
  4.     ...  
  5.     /* configure signal handling */  
  6.     if (!gDvm.reduceSignals)  
  7.         blockSignals();  
  8.     ...  
  9. }  

blockSignals()的实现很简答，它是通过 sigprocmask() 函数调用实现的，代码在init.c如下：
  1. /*  
  2.  * Configure signals.  We need to block SIGQUIT so that the signal only  
  3.  * reaches the dump-stack-trace thread.  
  4.  *  
  5.  * This can be disabled with the "-Xrs" flag.  
  6.  */  
  7. static void blockSignals()  
  8. {  
  9.     sigset_t mask;  
  10.     int cc;  
  11.   
  12.     sigemptyset(&mask);  
  13.     sigaddset(&mask, SIGQUIT);  
  14.     sigaddset(&mask, SIGUSR1);      // used to initiate heap dump  
  15. #if defined(WITH_JIT) && defined(WITH_JIT_TUNING)  
  16.     sigaddset(&mask, SIGUSR2);      // used to investigate JIT internals  
  17. #endif  
  18.     //sigaddset(&mask, SIGPIPE);  
  19.     cc = sigprocmask(SIG_BLOCK, &mask, NULL);  
  20.     assert(cc == 0);  
  21. }  

Step #2： DVM 生成单独的信号处理线程，用来对三个信号做特殊处理 （init.c）：
  1. /*  
  2.  * Do non-zygote-mode initialization.  This is done during VM init for  
  3.  * standard startup, or after a "zygote fork" when creating a new process.  
  4.  */  
  5. bool dvmInitAfterZygote(void)  
  6. {  
  7.     ...  
  8.     /* start signal catcher thread that dumps stacks on SIGQUIT */  
  9.     if (!gDvm.reduceSignals && !gDvm.noQuitHandler) {  
  10.         if (!dvmSignalCatcherStartup())  
  11.             return false;  
  12.     }  
  13.     ...  
  14. }  
dvmSignalCatcherStartup() 实现在 SignalCatcher.c 中：
  1. /*  
  2.  * Crank up the signal catcher thread.  
  3.  *  
  4.  * Returns immediately.  
  5.  */  
  6. bool dvmSignalCatcherStartup(void)  
  7. {  
  8.     gDvm.haltSignalCatcher = false;  
  9.   
  10.     if (!dvmCreateInternalThread(&gDvm.signalCatcherHandle,  
  11.                 "Signal Catcher", signalCatcherThreadStart, NULL))  
  12.         return false;  
  13.   
  14.     return true;  
  15. }  

我们看到，DVM调用dvmCreateInternalThread()来生成一个新的内部线程 来专门处理dvm进程里的信号。 后面我们会看到，dvmCreateInternalThread()其实是使用pthread_create()来产生新的线程。 该线程的处理函数是 signalCatcherThreadStart()。  （dvm里所谓的 内部线程，就是用来帮助dvm实现本身使用的线程，比如 信号处理线程，binder线程，Compiler线程，JDWP线程等，而不是应用程序申请的线程。 在后面我们计划用专门的一章来讨论DVM线程模式）

signalCatcherThreadStart() 实现框架如下：

  1. /*  
  2.  * Sleep in sigwait() until a signal arrives.  
  3.  */  
  4. static void* signalCatcherThreadStart(void* arg)  
  5. {  
  6.     ...  
  7.     /* set up mask with signals we want to handle */  
  8.     sigemptyset(&mask);  
  9.     sigaddset(&mask, SIGQUIT);  
  10.     sigaddset(&mask, SIGUSR1);  
  11. #if defined(WITH_JIT) && defined(WITH_JIT_TUNING)  
  12.     sigaddset(&mask, SIGUSR2);  
  13. #endif  
  14.     ...  
  15.     while (true) {  
  16.     ...  
  17. loop:  
  18.         cc = sigwait(&mask, &rcvd);  
  19.         ...  
  20.         switch (rcvd) {  
  21.         case SIGQUIT:  
  22.             handleSigQuit();  
  23.             break;  
  24.         case SIGUSR1:  
  25.             handleSigUsr1();  
  26.             break;  
  27. #if defined(WITH_JIT) && defined(WITH_JIT_TUNING)  
  28.         case SIGUSR2:  
  29.             handleSigUsr2();  
  30.             break;  
  31. #endif  
  32.         ...  
  33. }  
它首先设置我们要处理的信号集(SIGQUIT, SIGUSR1, SIGUSR2), 然后 调用 sigwait()。 我们知道sigwait()会在当前的线程里 重新 打开 指定的信号屏蔽字屏蔽的信号集。  在刚才的分析中，我们看到，dvm在启动时，首先在整个进程里设置信号屏蔽字屏蔽掉三个信号，sigwait()的调用，使的这三个信号只在 SignalCatcher线程里响应。

至此我们已经能够看到，dvm对三个信号分别所做的特殊用途：

1. SIGUSR1 被用来 做手工垃圾收集。处理函数是 HandleSigUsr1()

  1. static void handleSigUsr1(void)  
  2. {  
  3.     LOGI("SIGUSR1 forcing GC (no HPROF)\n");  
  4.     dvmCollectGarbage(false);  
  5. }  

2. SIGUSR2 被用来做 JIT的调试。如果JIT下编译时打开，收到SIGUSR2是dvm会dump出相关的调试信息。处理逻辑如下：
  1. #if defined(WITH_JIT) && defined(WITH_JIT_TUNING)  
  2. /*  
  3.  * Respond to a SIGUSR2 by dumping some JIT stats and possibly resetting  
  4.  * the code cache.  
  5.  */  
  6. static void handleSigUsr2(void)  
  7. {  
  8.     static int codeCacheResetCount = 0;  
  9.     if ((--codeCacheResetCount & 7) == 0) {  
  10.         gDvmJit.codeCacheFull = true;  
  11.     } else {  
  12.         dvmCompilerDumpStats();  
  13.         /* Stress-test unchain all */  
  14.         dvmJitUnchainAll();  
  15.         LOGD("Send %d more signals to rest the code cache",  
  16.              codeCacheResetCount & 7);  
  17.     }  
  18. }  
  19. #endif  

由于以上两个信号都仅用于DVM的内部实现的调试，本文不作详细的分析。读者可以在终端通过adb发送 SIGUSR1 和SIGUSR2信号来观察它的行为。

 

3.  SIGQUIT 用来 输出trace文件，以记录异常终止是dvm的上下文信息.

SIGQUIT的处理函数如下所示：

  1. static void handleSigQuit(void)  
  2. {   ...  
  3.     dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP);  
  4.   
  5.     if (gDvm.stackTraceFile == NULL) {  
  6.         /* just dump to log */  
  7.         DebugOutputTarget target;  
  8.         dvmCreateLogOutputTarget(&target, ANDROID_LOG_INFO, LOG_TAG);  
  9.         dvmDumpAllThreadsEx(&target, true);  
  10.     } else {  
  11.         /* write to memory buffer */  
  12.         FILE* memfp = open_memstream(&traceBuf, &traceLen);  
  13.         if (memfp == NULL) {  
  14.             LOGE("Unable to create memstream for stack traces\n");  
  15.             traceBuf = NULL;        /* make sure it didn't touch this */  
  16.             /* continue on */  
  17.         } else {  
  18.             logThreadStacks(memfp);  
  19.             fclose(memfp);  
  20.         }  
  21.     }  
  22.   
  23. #if defined(WITH_JIT) && defined(WITH_JIT_TUNING)  
  24.     dvmCompilerDumpStats();  
  25. #endif  
  26.   
  27.     dvmResumeAllThreads(SUSPEND_FOR_STACK_DUMP);  
  28.   
  29.     if (traceBuf != NULL) {  
  30.         int fd = open(gDvm.stackTraceFile, O_WRONLY | O_APPEND | O_CREAT, 0666);  
  31.         if (fd < 0) {  
  32.             LOGE("Unable to open stack trace file '%s': %s\n",  
  33.                 gDvm.stackTraceFile, strerror(errno));  
  34.         } else {  
  35.         ...  
  36.         }  
  37.     ...  
  38. }  

它首先查看有木有指定 trace输出文件，没有就将trace信息打印到log里。如果有，就先将trace信息打印到内存文件中，然后再讲改内存文件内容输出到指定trace文件中。

有些读者肯能觉得奇怪，为什么指定了trace文件后，不直接打印trace信息到trace文件中呢。 原因是 trace文件实际上记录的是当前运行的所有的线程的上下文信息。他需要 暂停所有的线程才能输出。 dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP);的调用正式这个目的。可以看出，这个操作代价是很高的，它把当前所有的线程都停了下来。执行的时间越短，对正常运行的线程的影响越小。 输出信息到内存比直接到外部文件要快得多。所以 dvm采取了先输出到内存，马上恢复线程程，然后就可以慢慢的输出到外部文件里了。

而这真正的输出信息实现在 logThreadStacks()中：

  1. static void logThreadStacks(FILE* fp)  
  2. {  
  3.     dvmPrintDebugMessage(&target,  
  4.         "\n\n----- pid %d at %04d-%02d-%02d %02d:%02d:%02d -----\n",  
  5.         pid, ptm->tm_year + 1900, ptm->tm_mon+1, ptm->tm_mday,  
  6.         ptm->tm_hour, ptm->tm_min, ptm->tm_sec);  
  7.     printProcessName(&target);  
  8.     dvmPrintDebugMessage(&target, "\n");  
  9.     dvmDumpAllThreadsEx(&target, true);  
  10.     fprintf(fp, "----- end %d -----\n", pid);  
  11. }  
该函数打印了trace文件的框架，其输出类似如下所示：
  1. ----- pid 503 at 2011-11-21 21:59:12 -----  
  2. Cmd line: com.android.phone  
  3.   
  4. <Thread_info>  
  5.   
  6. ----- end 503 -----  
它显示当前dvm进程的进程id，名字，输出的时间。最重要的所有线程的上下文信息是有函数 dvmDumpAllThreadsEx()里实现的，该函数定义在 thread.c里：
  1. void dvmDumpAllThreadsEx(const DebugOutputTarget* target, bool grabLock)  
  2. {  
  3.     Thread* thread;  
  4.   
  5.     dvmPrintDebugMessage(target, "DALVIK THREADS:\n");  
  6.   
  7. #ifdef HAVE_ANDROID_OS  
  8.     dvmPrintDebugMessage(target,  
  9.         "(mutexes: tll=%x tsl=%x tscl=%x ghl=%x hwl=%x hwll=%x)\n",  
  10.         gDvm.threadListLock.value,  
  11.         gDvm._threadSuspendLock.value,  
  12.         gDvm.threadSuspendCountLock.value,  
  13.         gDvm.gcHeapLock.value,  
  14.         gDvm.heapWorkerLock.value,  
  15.         gDvm.heapWorkerListLock.value);  
  16. #endif  
  17.   
  18.     if (grabLock)  
  19.         dvmLockThreadList(dvmThreadSelf());  
  20.   
  21.     thread = gDvm.threadList;  
  22.     while (thread != NULL) {  
  23.         dvmDumpThreadEx(target, thread, false);  
  24.   
  25.         /* verify link */  
  26.         assert(thread->next == NULL || thread->next->prev == thread);  
  27.   
  28.         thread = thread->next;  
  29.     }  
  30.   
  31.     if (grabLock)  
  32.         dvmUnlockThreadList();  
  33. }  

它的输出格式如下：
  1. DALVIK THREADS:  
  2. (mutexes: tll=0 tsl=0 tscl=0 ghl=0 hwl=0 hwll=0)  
  3. "main" prio=5 tid=1 NATIVE  
  4.   | group="main" sCount=1 dsCount=0 obj=0x400246a0 self=0x12770  
  5.   | sysTid=503 nice=0 sched=0/0 cgrp=default handle=-1342909272  
  6.   | schedstat=( 15165039025 12197235258 23068 ) utm=182 stm=1334 core=0  
  7.   at android.os.MessageQueue.nativePollOnce(Native Method)  
  8.   at android.os.MessageQueue.next(MessageQueue.java:119)  
  9.   at android.os.Looper.loop(Looper.java:122)  
  10.   at android.app.ActivityThread.main(ActivityThread.java:4134)  
  11.   at java.lang.reflect.Method.invokeNative(Native Method)  
  12.   at java.lang.reflect.Method.invoke(Method.java:491)  
  13.   at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:841)  
  14.   at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:599)  
  15.   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异常终止的原因。敬请期待