跟蹤 UNIX 應用程序的解決方案

本文示例源代碼或素材下載

開始之前

本教程幫助 Unix 系統開發人員和管理員以最佳方式跟蹤系統上運行的應用程序。要想從本教程獲得最大收獲，您應該了解 UNIX 操作系統的基本知識及其操作方式。具備基本的編程經驗會有幫助，但不是必需的。

關于本教程

大多數開發人員和系統管理員知道在他們的操作系統和應用程序中應該會發生什么情況，但糟糕的是，有時候不是這樣的。當應用程序崩潰或表現異常時，需要查明更多信息。通過利用對應用程序正常工作方式的了解和一些基本 UNIX 技能，可以跟蹤應用程序，查明造成問題的原因。本教程講解使用跟蹤工具了解應用程序內部情況的基本技術。

本教程首先討論調試和跟蹤的差異，以及這兩種解決方案的工作方式差異。然后，通過一些具體示例講解如何使用跟蹤解決應用程序中的問題。DTrace 提供跟蹤和調試兩種系統的組件，還支持對應用程序進行計時和基準測試。最后，本教程講解如何跟蹤在網絡計算機之間交換的信息，幫助發現網絡應用程序中的問題。

跟蹤概述

有時候，需要了解在應用程序內部正在發生的情況。例如，應用程序可能會運行失敗，而又沒有顯示有幫助的錯誤消息，或者系統服務沒有按照預期的方式運行。在這些情況下，您可能不掌握應用程序源代碼，因此無法通過傳統的調試過程尋找問題的原因。跟蹤提供了一種替代方法。

調試

對于開發人員來說，尋找 UNIX 應用程序問題的主要方法是，使用開發環境或操作系統的調試特性檢查源代碼，查明造成問題的原因。

大多數調試系統支持逐行監視和檢查代碼行的執行過程，還支持監視變量和結構的值。可以使用調試器在代碼中設置斷點，執行過程會停在斷點上；在斷點上，可以獲得關于調用堆棧（函數的調用路徑）的信息以及變量值。

我們來看一個例子，假設一個應用程序根據人的生日計算他的年齡，還要考慮到閏年等因素。要想調試這個應用程序，需要有源代碼，還需要在啟用調試選項的情況下編譯應用程序：$ gcc -g ageindays.c -o ageindays。

運行這個應用程序，提供用戶的生日和用來比較的目標日期（見清單 1）。

清單 1. 執行比較

$　./ageindays　24/1/1980　22/2/2009　You　have　been　alive　10622　days　You　were　born　on　24/1/1980　which　is　a　Thursday　

在調試應用程序時，首先懷疑問題出在 calc_diff 函數中，這個函數計算第一個和第二個日期的差。接下來，可能按照清單 2 這樣進行調試。

清單 2. 調試 calc_diff 函數

$　gdb　ageindays　GNU　gdb　6.3.50-20050815　(Apple　version　gdb-962)　(Sat　Jul　26　08:14:40　UTC　2008)　Copyright　2004　Free　Software　Foundation,　Inc.　GDB　is　free　software,　covered　by　the　GNU　General　Public　License,　and　you　are　welcome　to　change　it　and/or　distribute　copIEs　of　it　under　certain　conditions.　Type　"show　copying"　to　see　the　conditions.　There　is　absolutely　no　warranty　for　GDB.　Type　"show　warranty"　for　details.　This　GDB　was　configured　as　"i386-apple-darwin"...Reading　symbols　for　shared　libraries　...　done　　(gdb)　b　calc_diff　Breakpoint　1　at　0x1bd7:　file　ageindays.c,　line　27.　(gdb)　r　24/1/1980　26/3/2009　Starting　program:　/nfs/MC/UnixSrc/c/bio/ageindays　24/1/1980　26/3/2009　Reading　symbols　for　shared　libraries　++.　done　　Breakpoint　1,　calc_diff　(day=26,　month=3,　year=2009)　at　ageindays.c:27　27unsigned　long　days_diff=0;　(gdb)　bt　#0　calc_diff　(day=26,　month=3,　year=2009)　at　ageindays.c:27　#1　0x00001e3d　in　main　(argc=3,　argv=0xbffff708)　at　ageindays.c:89　(gdb)　p　days_diff　$1　=　8041　(gdb)　

通過 清單 2 中的輸出可以看出，我們打開了調試器，通過指定名稱在 calc_diff() 函數中設置了一個斷點，然后在調試器中運行程序，提供與命令行相同的參數。

當調試器到達創建的斷點時，執行過程停止，您可以檢查應用程序代碼和調用的函數。通過使用調試器，可以查看提供給函數的參數及其值（在這里是為目標日期提供的日期信息）。執行停止之后，可以查看堆棧跟蹤，查看代碼中調用 calc_diff 函數的行，可以獲得 days_diff 變量的值。因為應用程序的執行過程已經暫停了，所以還可以修改變量的值。這樣就可以在應用程序中嘗試使用不同的值，從而尋找潛在的問題。

可以使用這些信息，因為定義了特定的調試信息（組成函數和變量名的符號）和其他元數據（比如定義函數的代碼行）。

必須在編譯時把特定的調試信息添加到二進制應用程序中；更重要的是，必須訪問源代碼，才能把調試信息包含在編譯的應用程序中。如果無法識別函數名和變量，那么幾乎不可能調試程序。

跟蹤與調試的對比

系統管理員（和開發人員）常常希望發現正在運行的程序中的錯誤。例如，某個程序為什么造成了其他問題（比如內存和其他錯誤），應用程序的表現為什么不符合預期，它過去發生了什么情況。在這種情況下，調試應用程序的特定方面往往沒什么用。需要查明的實際上是操作系統如何執行應用程序。

在進行調試時，檢查的是應用程序中定義的各個函數的執行過程。調試主要關注應用程序本身，包括其中的函數和結構，通常會忽視應用程序向操作系統發出的系統調用和庫函數調用。調試能夠提供關于應用程序的大量信息，但是對于了解操作系統如何執行應用程序幫助不大。

在進行跟蹤時，監視應用程序和操作系統之間的交互，常常會檢查應用程序在執行期間調用的操作系統函數。

除了這些差異之外，跟蹤和調試之間的主要差異是，跟蹤不要求訪問源代碼，也不要求以任何特殊方式編譯應用程序。這意味著可以跟蹤操作系統附帶的或第三方廠商提供的應用程序。

通過跟蹤應用程序，可以查明以下方面的情況：

內存使用量和映射內存的調用

在執行期間打開和關閉的文件

對不同文件的讀和寫操作

為給定的應用程序裝載的庫

下面先研究一下 truss 的輸出，truss 是一種可以在 Solaris 和 AIX® 上使用的工具。

使用 truss 和 strace

在 Solaris 和 AIX 上可以使用 truss 工具，它能夠跟蹤應用程序中的系統調用和信號?？梢栽?Linux® 上使用的 strace 工具提供相似的功能。在不同的系統上，還有提供相似信息的其他工具，包括 ktrace (FreeBSD) 和 trace。

truss/strace 概述

truss 和 strace 工具提供相似的信息，但是命令行選項稍有差異。使用這兩種工具的標準方法都是把工具名放在要執行的命令前面。

例如，清單 3 給出 truss 對于本教程前面提到的 ageindays 程序的輸出。

清單 3. truss 的輸出

$　truss　./ageindays　24/1/1980　26/3/2009　execve("ageindays",　0x08047BBC,　0x08047BCC)　argc　=　3　mmap(0x00000000,　4096,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_ANON,　-1,　0)　=　0xFEFB0000　resolvepath("/usr/lib/ld.so.1",　"/lib/ld.so.1",　1023)　=　12　getcwd("/root",　1013)=　0　resolvepath("/root/ageindays",　"/root/ageindays",　1023)　=　15　xstat(2,　"/root/ageindays",　0x08047880)　=　0　open("/var/ld/ld.config",　O_RDONLY)　=　3　fxstat(2,　3,　0x08047760)=　0　mmap(0x00000000,　144,　PROT_READ,　MAP_SHARED,　3,　0)　=　0xFEFA0000　close(3)=　0　sysconfig(_CONFIG_PAGESIZE)　=　4096　xstat(2,　"/usr/lib/libc.so.1",　0x08046FA0)　=　0　resolvepath("/usr/lib/libc.so.1",　"/lib/libc.so.1",　1023)　=　14　open("/usr/lib/libc.so.1",　O_RDONLY)=　3　mmap(0x00010000,　32768,　PROT_READ|PROT_EXEC,　MAP_PRIVATE|MAP_ALIGN,　3,　0)　=　0xFEF90000　mmap(0x00010000,　1413120,　PROT_NONE,　MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN,　-1,　0)　=　0xFEE30000　mmap(0xFEE30000,　1302809,　PROT_READ|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|MAP_TEXT,　3,　0)　=　0xFEE30000　mmap(0xFEF7F000,　30862,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|　MAP_INITDATA,　3,　1306624)　=　0xFEF7F000　mmap(0xFEF87000,　4776,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|MAP_ANON,　-1,　0)　=　0xFEF87000　munmap(0xFEF6F000,　65536)=　0　memcntl(0xFEE30000,　187632,　MC_ADVISE,　MADV_WILLNEED,　0,　0)　=　0　close(3)=　0　mmap(0x00010000,　24576,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_ANON|MAP_ALIGN,　-1,　0)　=　0xFEE20000　munmap(0xFEF90000,　32768)=　0　getcontext(0x080475D0)　getrlimit(RLIMIT_STACK,　0x080475C8)　=　0　getpid()=　15691　[15690]　lwp_private(0,　1,　0xFEE22A00)=　0x000001C3　setustack(0xFEE22A60)　sysi86(SI86FPSTART,　0xFEF879BC,　0x0000133F,　0x00001F80)　=　0x00000001　ioctl(1,　TCGETA,　0x08046C20)=　0　fstat64(1,　0x08046B80)　=　0　You　have　been　alive　10654　days　write(1,　"　Y　o　uh　a　v　eb　e　e"..,　31)　=　31　You　were　born　on　24/1/1980　which　is　a　Thursday　write(1,　"　Y　o　uw　e　r　eb　o　r"..,　47)　=　47　_exit(134511508)　

在這兩個輸出中，每個輸出行對應于應用程序執行的一個函數調用，其中顯示函數的參數和函數調用的返回值。與調試示例不同，列出的每個函數調用都是系統或系統庫中的函數，因此表示調用的函數的更低層接口。例如，在應用程序中可能使用 C 或 C++ 中的 fpopen() 函數打開文件，但是這個函數實際上是更低層的 open() 函數的包裝器。

了解應用程序正在執行的操作并不需要了解每個函數的情況。輸出中的許多行與操作系統為裝載和執行程序所做的初始化相關。這兩個跟蹤輸出的基本結構是相同的：

調用 execve() 函數以啟動一個新程序。

裝載程序所需的庫。在 Solaris 輸出中，首先使用 resolvepath() 尋找庫，然后使用 open() 打開庫。對于 Linux，使用 stat() 檢查庫是否存在，然后使用 open() 打開它。

為進程保留和分配一些內存。其中一部分內存是為應用程序保留的堆棧空間，一部分用來保存程序，其他內存保存程序使用的變量。

最后，執行程序，調用 write() 函數輸出年齡和生日信息。

如果執行跟蹤并希望了解每個步驟的具體情況，可以使用 man 命令訪問每個函數的手冊頁。

識別應用程序啟動問題

在啟動應用程序時的一個典型問題是，程序無法正確地初始化，但是在終止時給出一個不完整或導致誤解的消息。對應用程序運行跟蹤常常可以揭示這個問題的根源。例如，清單 5 顯示一個測試應用程序運行失敗了。

清單 5. 應用程序失敗

$　./errnoacc　ERROR:　Application　failed　to　initialize　

錯誤消息并沒有提供關于應用程序為什么會啟動失敗的具體信息。在這里，問題是故意引入的，但是您使用的任何命令或應用程序都可能出現相同的問題，而錯誤消息沒什么幫助，有時候甚至沒有錯誤消息。

對應用程序運行跟蹤可能會提供一些線索（見清單 6）。

清單 6. 運行跟蹤

$　truss　./errnoacc　execve("errnoacc",　0x08047B20,　0x08047B28)　argc　=　1　mmap(0x00000000,　4096,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_ANON,　-1,　0)　=　0xFEFB0000　resolvepath("/usr/lib/ld.so.1",　"/lib/ld.so.1",　1023)　=　12　getcwd("/export/home/mc",　1014)　=　0　resolvepath("/export/home/mc/errnoacc",　"/export/home/mc/errnoacc",　1023)　=　24　xstat(2,　"/export/home/mc/errnoacc",　0x080477E4)　=　0　open("/var/ld/ld.config",　O_RDONLY)　=　3　fxstat(2,　3,　0x080476C4)=　0　mmap(0x00000000,　144,　PROT_READ,　MAP_SHARED,　3,　0)　=　0xFEFA0000　close(3)=　0　sysconfig(_CONFIG_PAGESIZE)　=　4096　xstat(2,　"/usr/lib/libc.so.1",　0x08046F04)　=　0　resolvepath("/usr/lib/libc.so.1",　"/lib/libc.so.1",　1023)　=　14　open("/usr/lib/libc.so.1",　O_RDONLY)=　3　mmap(0x00010000,　32768,　PROT_READ|PROT_EXEC,　MAP_PRIVATE|MAP_ALIGN,　3,　0)　=　0xFEF90000　mmap(0x00010000,　1413120,　PROT_NONE,　MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN,　-1,　0)　=　0xFEE30000　mmap(0xFEE30000,　1302809,　PROT_READ|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|MAP_TEXT,　3,　0)　=　0xFEE30000　mmap(0xFEF7F000,　30862,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|　MAP_INITDATA,　3,　1306624)　=　0xFEF7F000　mmap(0xFEF87000,　4776,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_FIXED|MAP_ANON,　-1,　0)　=　0xFEF87000　munmap(0xFEF6F000,　65536)=　0　memcntl(0xFEE30000,　187632,　MC_ADVISE,　MADV_WILLNEED,　0,　0)　=　0　close(3)=　0　mmap(0x00010000,　24576,　PROT_READ|PROT_WRITE|PROT_EXEC,　MAP_PRIVATE|MAP_ANON|MAP_ALIGN,　-1,　0)　=　0xFEE20000　munmap(0xFEF90000,　32768)=　0　getcontext(0x08047534)　getrlimit(RLIMIT_STACK,　0x0804752C)　=　0　getpid()=　15727　[15726]　lwp_private(0,　1,　0xFEE22A00)=　0x000001C3　setustack(0xFEE22A60)　sysi86(SI86FPSTART,　0xFEF879BC,　0x0000133F,　0x00001F80)　=　0x00000001　open("/etc/shadow",　O_RDONLY)Err#13　EACCES　[file_dac_read]　ioctl(1,　TCGETA,　0x08046BB0)=　0　fstat64(1,　0x08046B10)　=　0　ERROR:　Application　failed　to　initialize　write(1,　"　E　R　R　O　R　:A　p　p　l　i"..,　40)　=　40　_exit(0)　

問題出現在這一行上：open("/etc/shadow", O_RDONLY) Err#13 EACCES [file_dac_read]。

在這里，應用程序試圖打開一個文件，但是因為有文件權限保護這個文件，運行應用程序的用戶沒有訪問權。因為無法打開這個文件，應用程序終止并在進程中寫錯誤消息。

跟蹤正在運行的應用程序

希望跟蹤應用程序常常是因為應用程序已經啟動，而您希望查明應用程序為什么不工作了。與初始化示例一樣，應用程序提供的錯誤消息或其他信息常常沒有準確地指出問題。

試圖鎖定或訪問另一個進程正在使用的資源會使應用程序看起來凍結了，沒有響應。

strace 和 truss 都能夠 “連接 到正在運行的進程。連接到進程的跟蹤與從命令行運行進程的跟蹤相似，也產生程序正在執行的系統函數的列表。實際的跟蹤從跟蹤啟動時執行的函數開始；對于在執行期間 “掛起 的程序，跟蹤應該會顯示程序正在等待的函數。

要想跟蹤正在運行的程序，需要指定要跟蹤的進程的進程 ID (PID)。例如，在清單 6 中，跟蹤的程序已經停止，但是沒有報告錯誤。這里使用 ps 工具列出正在運行的進程（見清單 7）。

清單 7. 使用 ps 工具列出正在運行的進程

$　ps　-ef|grep　errlock　　mc　15779　157470　18:26:59　pts/20:00　./errlock　　mc　157426800　18:26:36　pts/30:00　./errlock　　mc　15817　157840　18:28:44　pts/40:00　grep　errlock　　mc　157346800　18:25:00　pts/30:01　/usr/bin/eMacs-nox　errlock.c　$　truss　-p　15779　fcntl(3,　F_SETLKW,　0x08047AC4)　(sleeping...)　

在輸出中可以看到，已經調用了 fcntl() 函數，它要在一個文件上設置鎖。在這里，這個函數會一直等待到成功地設置鎖，然后才繼續運行。不幸的是，另一個進程已經鎖住了這個文件，所以第二個應用程序必須等待第一個應用程序使用完文件并釋放鎖。

對于這種情況，truss 有點兒局限性：它無法指出要鎖住哪個文件，也無法指出當前鎖住了哪個文件，從而阻礙了第二個程序的執行。這是因為跟蹤過程是在已經調用了打開文件的函數之后啟動的。truss 和 strace 只跟蹤在它們執行期間調用的函數；它們無法查明已經調用的函數。

獲取堆棧跟蹤

可以看出，truss 對于監視整個程序很有用，但是對于監視已經啟動的程序可能有點兒局限性。如果使用基于 SVR4 的 Unix，比如 Solaris 或 AIX，那么 pstack 命令可能有幫助。

pstack 命令實際上屬于一組進程檢查命令，這些命令輸出正在運行的進程的相關信息。其他工具包括 pfiles（輸出進程使用的文件的列表）和 psig（顯示信號和信號處理函數的列表）。

在使用這些命令時，需要指定進程的 PID。pstack 命令輸出一個正在運行的進程的調用堆棧，顯示在進程到達當前函數之前調用的函數。例如，對正在等待被鎖住的文件的進程使用 pstack，會產生清單 8 中的輸出。

清單 8. 對正在等待被鎖住的文件的進程使用 pstack

$　pstack　15828　15828:　./errlock　　feef0877　fcntl(3,　7,　8047ac4)　　feedcd49　fcntl(3,　7,　8047ac4,　8050e74)　+　91　　08050f10　main　(1,　8047b24,　8047b2c)　+　d8　　08050cdc　_start(1,　8047c08,　0,　8047c12,　8047c7d,　8047c8e)　+　80　

在這里，它沒有提供我們需要的信息?，F在試試 pfiles（見清單 9）。

清單 9. 使用 pfiles

$　pfiles　15856　15856:　./errlock　　Current　rlimit:　256　file　descriptors　0:　S_IFCHR　mode:0620　dev:292,0　ino:989038936　uid:101　gid:7　rdev:24,3　　O_RDWR|O_NOCTTY|O_LARGEFILE　　/dev/pts/3　1:　S_IFCHR　mode:0620　dev:292,0　ino:989038936　uid:101　gid:7　rdev:24,3　　O_RDWR|O_NOCTTY|O_LARGEFILE　　/dev/pts/3　2:　S_IFCHR　mode:0620　dev:292,0　ino:989038936　uid:101　gid:7　rdev:24,3　　O_RDWR|O_NOCTTY|O_LARGEFILE　　/dev/pts/3　3:　S_IFREG　mode:0666　dev:182,65545　ino:198　uid:101　gid:10　size:0　　O_RDWR　　advisory　write　lock　set　by　process　15828　　/export/home/mc/lockdemo　

這些輸出就比較有用了。可以看到進程已經打開的文件稱為 lockdemo ，因為 truss 顯示正在等待文件鎖，所以可能是這個文件導致了問題。

truss 和 strace 都是被動的跟蹤?？梢圆榭凑趫绦械暮瘮担菬o法了解關于正在發生的情況的詳細信息，也無法更有針對性地指定要跟蹤的東西和跟蹤時要輸出的信息。

用 DTrace 進行動態跟蹤

Solaris、FreeBSD 和 Mac OS X 內置的 Dynamic Tracing (DTrace) 功能提供一個更加動態的跟蹤環境。與 truss 和相似的工具不同，可以使用 DTrace 檢查正在運行的程序的內部情況，而不只是查看系統調用。另外，可以使用 DTrace 編寫應用程序跟蹤腳本，從而定制在跟蹤過程中希望提取的信息。