在前一章Android 信號(hào)處理面面觀 之 信號(hào)定義、行為和來(lái)源 中，我們討論過(guò)，Android 應(yīng)用在收到異常終止信號(hào)（SIGQUIT）時(shí)，沒(méi)有遵循傳統(tǒng)
UNIX信號(hào)模型的默認(rèn)行為 （終止 + core ）。而是打印出trace 文件來(lái)，以利于記錄應(yīng)用異常終止的原因。 本文就重點(diǎn)分析 trace 文件是怎么產(chǎn)生的，并詳細(xì)解釋trace文件的各個(gè)字段的含義。
一. TRACE 文件的產(chǎn)生
Trace文件是 android davik 虛擬機(jī)在收到異常終止信號(hào) （SIGQUIT）時(shí)產(chǎn)生的。 最經(jīng)常的觸發(fā)條件是 android應(yīng)用中產(chǎn)生了 FC （force close）。由于是該文件的產(chǎn)生是在 DVM里，所以只有運(yùn)行 dvm實(shí)例的進(jìn)程（如普通的java應(yīng)用，java服務(wù)等）才會(huì)產(chǎn)生該文件，android 本地應(yīng)用 （native app，指 運(yùn)行在 android lib層，用c/c++編寫(xiě)的linux應(yīng)用、庫(kù)、服務(wù)等）在收到 SIGQUIT時(shí)是不會(huì)產(chǎn)生 trace文件的。
如上文Android 信號(hào)處理面面觀 之 信號(hào)定義、行為和來(lái)源所述，我們可以在終端通過(guò)adb發(fā)送SIGQUIT給應(yīng)用來(lái)生成trace文件。
二. TRACE文件的實(shí)現(xiàn)
相關(guān)實(shí)現(xiàn)在以下幾個(gè)文件中：
dalvik/vm/init.h [.c]
davik/vm/SignalCatcher.h[.c]
dalvik/vm/Thread.h[.c]
Android ICS 實(shí)現(xiàn)文件后綴是 .cpp。
實(shí)現(xiàn)過(guò)程分以下幾步：
Step #1: DVM初始化時(shí)，設(shè)置信號(hào)屏蔽字，屏蔽要特殊處理的信號(hào)(SIGQUIT, SIGUSR1, SIGUSR2)。由于信號(hào)處理方式是進(jìn)程范圍起作用的， 這意味著該進(jìn)程里所有的線程都將屏蔽該信號(hào)。 實(shí)現(xiàn)代碼在init.c中如下：
- int dvmStartup(int argc, const char* const argv[], bool ignoreUnrecognized,
- JNIEnv* pEnv)
- {
- ...
- /* configure signal handling */
- if (!gDvm.reduceSignals)
- blockSignals();
- ...
- }
blockSignals()的實(shí)現(xiàn)很簡(jiǎn)答，它是通過(guò) sigprocmask() 函數(shù)調(diào)用實(shí)現(xiàn)的，代碼在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 生成單獨(dú)的信號(hào)處理線程，用來(lái)對(duì)三個(gè)信號(hào)做特殊處理 （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() 實(shí)現(xiàn)在 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調(diào)用dvmCreateInternalThread()來(lái)生成一個(gè)新的內(nèi)部線程 來(lái)專(zhuān)門(mén)處理dvm進(jìn)程里的信號(hào)。 后面我們會(huì)看到，dvmCreateInternalThread()其實(shí)是使用pthread_create()來(lái)產(chǎn)生新的線程。 該線程的處理函數(shù)是 signalCatcherThreadStart()。 （dvm里所謂的 內(nèi)部線程，就是用來(lái)幫助dvm實(shí)現(xiàn)本身使用的線程，比如 信號(hào)處理線程，binder線程，Compiler線程，JDWP線程等，而不是應(yīng)用程序申請(qǐng)的線程。 在后面我們計(jì)劃用專(zhuān)門(mén)的一章來(lái)討論DVM線程模式）
signalCatcherThreadStart() 實(shí)現(xiàn)框架如下：
- /*
- * 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
- ...
- }
它首先設(shè)置我們要處理的信號(hào)集(SIGQUIT, SIGUSR1, SIGUSR2), 然后 調(diào)用 sigwait()。 我們知道sigwait()會(huì)在當(dāng)前的線程里 重新 打開(kāi) 指定的信號(hào)屏蔽字屏蔽的信號(hào)集。 在剛才的分析中，我們看到，dvm在啟動(dòng)時(shí)，首先在整個(gè)進(jìn)程里設(shè)置信號(hào)屏蔽字屏蔽掉三個(gè)信號(hào)，sigwait()的調(diào)用，使的這三個(gè)信號(hào)只在 SignalCatcher線程里響應(yīng)。
至此我們已經(jīng)能夠看到，dvm對(duì)三個(gè)信號(hào)分別所做的特殊用途：
1. SIGUSR1 被用來(lái) 做手工垃圾收集。處理函數(shù)是 HandleSigUsr1()
- static void handleSigUsr1(void)
- {
- LOGI("SIGUSR1 forcing GC (no HPROF)\n");
- dvmCollectGarbage(false);
- }
2. SIGUSR2 被用來(lái)做 JIT的調(diào)試。如果JIT下編譯時(shí)打開(kāi)，收到SIGUSR2是dvm會(huì)dump出相關(guān)的調(diào)試信息。處理邏輯如下：
- #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
由于以上兩個(gè)信號(hào)都僅用于DVM的內(nèi)部實(shí)現(xiàn)的調(diào)試，本文不作詳細(xì)的分析。讀者可以在終端通過(guò)adb發(fā)送 SIGUSR1 和SIGUSR2信號(hào)來(lái)觀察它的行為。
3. SIGQUIT 用來(lái) 輸出trace文件，以記錄異常終止是dvm的上下文信息.
SIGQUIT的處理函數(shù)如下所示：
- 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輸出文件，沒(méi)有就將trace信息打印到log里。如果有，就先將trace信息打印到內(nèi)存文件中，然后再講改內(nèi)存文件內(nèi)容輸出到指定trace文件中。
有些讀者肯能覺(jué)得奇怪，為什么指定了trace文件后，不直接打印trace信息到trace文件中呢。 原因是 trace文件實(shí)際上記錄的是當(dāng)前運(yùn)行的所有的線程的上下文信息。他需要 暫停所有的線程才能輸出。 dvmSuspendAllThreads(SUSPEND_FOR_STACK_DUMP);的調(diào)用正式這個(gè)目的?？梢钥闯?，這個(gè)操作代價(jià)是很高的，它把當(dāng)前所有的線程都停了下來(lái)。執(zhí)行的時(shí)間越短，對(duì)正常運(yùn)行的線程的影響越小。 輸出信息到內(nèi)存比直接到外部文件要快得多。所以 dvm采取了先輸出到內(nèi)存，馬上恢復(fù)線程程，然后就可以慢慢的輸出到外部文件里了。
而這真正的輸出信息實(shí)現(xiàn)在 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);
- }
該函數(shù)打印了trace文件的框架，其輸出類(lèi)似如下所示：
- ----- pid 503 at 2011-11-21 21:59:12 -----
- Cmd line: com.android.phone
-
- <Thread_info>
-
- ----- end 503 -----
它顯示當(dāng)前dvm進(jìn)程的進(jìn)程id，名字，輸出的時(shí)間。最重要的所有線程的上下文信息是有函數(shù) dvmDumpAllThreadsEx()里實(shí)現(xiàn)的，該函數(shù)定義在 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. 第一行是 固定的頭, 指明下面的都是 當(dāng)前運(yùn)行的 dvm thread ：“DALVIK THREADS:”
2. 第二行輸出的是該 進(jìn)程里各種線程互斥量的值。（具體的互斥量的作用在 dalvik 線程一章 單獨(dú)陳述）
3. 第三行輸出分別是 線程的名字（“main”），線程優(yōu)先級(jí)（“prio=5”），線程id（“tid=1”） 以及線程的 類(lèi)型（“NATIVE”）
4. 第四行分別是線程所述的線程組 （“main”），線程被正常掛起的次處（“sCount=1”），線程因調(diào)試而掛起次數(shù)（”dsCount=0“），當(dāng)前線程所關(guān)聯(lián)的java線程對(duì)象（”obj=0x400246a0“）以及該線程本身的地址（“self=0x12770”）。
5. 第五行 顯示 線程調(diào)度信息。 分別是該線程在linux系統(tǒng)下得本地線程id （“ sysTid=503”），線程的調(diào)度有優(yōu)先級(jí)（“nice=0”），調(diào)度策略（sched=0/0），優(yōu)先組屬（“cgrp=default”）以及 處理函數(shù)地址（“handle=-1342909272”）
6 第六行 顯示更多該線程當(dāng)前上下文，分別是 調(diào)度狀態(tài)（從 /proc/[pid]/task/[tid]/schedstat讀出）（“schedstat=( 15165039025 12197235258 23068 )”），以及該線程運(yùn)行信息 ，它們是 線程用戶(hù)態(tài)下使用的時(shí)間值(單位是jiffies）（“utm=182”）， 內(nèi)核態(tài)下得調(diào)度時(shí)間值（“stm=1334”），以及最后運(yùn)行改線程的cup標(biāo)識(shí)（“core=0”）；
7.后面幾行輸出 該線程 調(diào)用棧。
有了以上信息，我們便更容易分析出app是為什么被異常終止的了。我們會(huì)在單獨(dú)的一章分析， 怎樣利用trace文件里的信息尋找app異常終止的原因。敬請(qǐng)期待。
