使用 Strace 進行故障排除的五種簡單方法

作者：碼農世界 2022-12-29 07:33:44

開發前端

Strace 非常簡單地是一個跟蹤系統調用執行的工具。在最簡單的形式中，它可以從頭到尾跟蹤二進制文件的執行，并輸出一行文本，其中包含系統調用的名稱、參數和進程生命周期內每個系統調用的返回值。

我一直感到驚訝的是，很少有人知道他們可以使用strace的所有事情。它始終是我推出的第一個調試工具之一，因為它通常在我運行的 Linux 系統上可用，并且可用于解決如此廣泛的問題。

什么是strace？

Strace 非常簡單地是一個跟蹤系統調用執行的工具。在最簡單的形式中，它可以從頭到尾跟蹤二進制文件的執行，并輸出一行文本，其中包含系統調用的名稱、參數和進程生命周期內每個系統調用的返回值。但它可以做更多的事情：

它可以根據特定的系統調用或系統調用組進行過濾
它可以通過計算特定系統調用的使用次數、所用時間以及成功和錯誤的數量來分析系統調用的使用情況。
它跟蹤發送到進程的信號。
它可以通過 pid 附加到任何正在運行的進程。

如果你使用過其他Unix系統，這類似于“truss”。另一個（更全面）是Sun的Dtrace。

如何使用它

這只是皮毛，沒有特別的重要性順序：

1）找出程序在啟動時讀取哪些配置文件

有沒有嘗試過弄清楚為什么某些程序不讀取您認為應該讀取的配置文件？不得不與自定義編譯或特定于發行版的二進制文件搏斗，這些二進制文件從您認為的“錯誤”位置讀取其配置？幼稚的方法：所以這個版本的PHP從/usr/local/lib/php.ini讀取php.ini（但它首先嘗試/usr/local/bin）。如果我只關心特定的系統調用，更復雜的方法：同樣的方法適用于許多其他事情。在不同的路徑上安裝了多個版本的庫，并想知道實際加載了哪個版本？等。

$ strace php 2>&1 | grep php.ini
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/php.ini", O_RDONLY) = 4
lstat64("/usr/local/lib/php.ini", {st_mode=S_IFLNK|0777, st_size=27, ...}) = 0
readlink("/usr/local/lib/php.ini", "/usr/local/Zend/etc/php.ini", 4096) = 27
lstat64("/usr/local/Zend/etc/php.ini", {st_mode=S_IFREG|0664, st_size=40971, ...}) = 0

$ strace -e open php 2>&1 | grep php.ini
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/php.ini", O_RDONLY) = 4

2）為什么這個程序打不開我的文件？

曾經遇到過一個程序，它默默地拒絕讀取它沒有讀取訪問權限的文件，但你只是在發誓多年后才發現，因為你認為它實際上沒有找到該文件？好吧，您已經知道該怎么做：查找失敗的 open（）或 access（）系統調用

$ strace -e open,access 2>&1 | grep your-filename

3）這個過程現在在做什么？

曾經有一個進程突然占用大量 CPU 嗎？還是一個過程似乎懸而未決？然后你找到pid，然后這樣做：啊。所以在這種情況下，它掛在對futex（）的調用中。順便說一下，在這種情況下，它并沒有告訴我們那么多 - 掛在 futex 上可能是由很多事情引起的（futex 是 Linux 內核中的鎖定機制）。以上來自一個正常工作但空閑的 Apache 子進程，該進程正在等待收到請求。但是“strace -p”非常有用，因為它消除了大量的猜測，并且通常不需要重新啟動具有更廣泛日志記錄的應用程序（甚至重新編譯它）。

root@dev:~# strace -p 15427
Process 15427 attached - interrupt to quit
futex(0x402f4900, FUTEX_WAIT, 2, NULL 
Process 15427 detached

4）什么是花時間？

你始終可以在打開分析的情況下重新編譯應用，并獲得準確的信息，尤其是關于你自己的代碼的哪些部分需要時間，這是你應該做的。但通常，能夠快速將 strace 附加到流程以查看它當前花費的時間（尤其是診斷問題）是非常有用的。這是 90% 的 CPU 使用率，因為它實際上正在做真正的工作，還是失控的東西。以下是您的操作：使用 -c -p 啟動 strace 后，您只需等待多長時間，然后使用 ctrl-c 退出。Strace 將按上述方式吐出分析數據。在這種情況下，它是一個空閑的 Postgres “postmaster” 進程，它花費大部分時間在 select（）中安靜地等待。在這種情況下，它在每次select（）調用之間調用getppid（）和time（），這是一個相當標準的事件循環。你也可以運行這個“從頭到尾”，這里用“ls”：幾乎你所期望的，它大部分時間都花在兩次調用上來讀取目錄條目（只有兩次，因為它是在一個小目錄上運行的）。

root@dev:~# strace -c -p 11084
Process 11084 attached - interrupt to quit
Process 11084 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 94.59    0.001014          48        21           select
  2.89    0.000031           1        21           getppid
  2.52    0.000027           1        21           time
------ ----------- ----------- --------- --------- ----------------
100.00    0.001072                    63           total
root@dev:~#

root@dev:~# strace -c >/dev/null ls
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 23.62    0.000205         103         2           getdents64
 18.78    0.000163          15        11         1 open
 15.09    0.000131          19         7           read
 12.79    0.000111           7        16           old_mmap
  7.03    0.000061           6        11           close
  4.84    0.000042          11         4           munmap
  4.84    0.000042          11         4           mmap2
  4.03    0.000035           6         6         6 access
  3.80    0.000033           3        11           fstat64
  1.38    0.000012           3         4           brk
  0.92    0.000008           3         3         3 ioctl
  0.69    0.000006           6         1           uname
  0.58    0.000005           5         1           set_thread_area
  0.35    0.000003           3         1           write
  0.35    0.000003           3         1           rt_sigaction
  0.35    0.000003           3         1           fcntl64
  0.23    0.000002           2         1           getrlimit
  0.23    0.000002           2         1           set_tid_address
  0.12    0.000001           1         1           rt_sigprocmask
------ ----------- ----------- --------- --------- ----------------
100.00    0.000868                    87        10 total

5）為什么 **** 我無法連接到該服務器？

調試某些進程未連接到遠程服務器的原因可能非常令人沮喪。DNS 可能會失敗，連接可能會掛起，服務器可能會發送一些意外的內容等。你可以使用 tcpdump 來分析很多，這也是一個非常好的工具，但很多時候 strace 會給你更少的喋喋不休，僅僅是因為它只會返回與“你的”進程生成的系統調用相關的數據。例如，如果您試圖弄清楚連接到同一數據庫服務器的數百個正在運行的進程中的一個是做什么的（其中挑選與 tcpdump 的正確連接是一場噩夢），strace 使生活變得容易得多。這是“nc”跟蹤連接到端口 80 上的 www.news.com 的示例，沒有任何問題：那么這里會發生什么？注意到 /var/run/nscd/socket 的連接嘗試了嗎？這意味著 nc 首先嘗試連接到 NSCD - 名稱服務緩存守護程序 - 通常用于依賴 NIS、YP、LDAP 或類似目錄協議進行名稱查找的設置中。在這種情況下，連接失敗。然后它移動到 DNS（DNS 是端口 53，因此在下面的連接中是“sin_port=htons（53）”。您可以看到它隨后執行“sendto（）”調用，發送包含 www.news.com 的DNS數據包。然后，它會讀回一個數據包。無論出于何種原因，它嘗試了三次，最后一次請求略有不同。在這種情況下，我最好的猜測是 www.news.com 是一個 CNAME（“別名”），多個請求可能只是 nc 如何處理它的人工制品。最后，它最終向它找到的 IP 發出 connect（）。請注意，它返回 EINPROGRESS。這意味著連接是非阻塞的 - nc 想要繼續處理。然后，它調用 select（），當連接成功時成功。嘗試將“read”和“write”添加到提供給strace的系統調用列表中，并在連接時輸入一個字符串，你會得到這樣的結果：這表明它從標準輸入讀取“test”+換行，并將其寫回網絡連接，然后調用poll（）等待回復，從網絡連接讀取回復并將其寫入標準輸出。一切似乎都正常。

$ strace -e poll,select,connect,recvfrom,sendto nc www.news.com 80
sendto(3, "\\24\\0\\0\\0\\26\\0\\1\\3\\255\\373NH\\0\\0\\0\\0\\0\\0\\0\\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "\\213\\321\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "\\213\\321\\201\\200\\0\\1\\0\\1\\0\\1\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 153
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "k\\374\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "k\\374\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
sendto(3, "\\\\\\2\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(3, "\\\\\\2\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("216.239.122.102")}, 16) = -1 EINPROGRESS (Operation now in progress)
select(4, NULL, [3], NULL, NULL)        = 1 (out [3])

read(0, "test\\n", 1024)                 = 5
write(3, "test\\n", 5)                   = 5
poll([{fd=3, events=POLLIN, revents=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1
read(3, "\"-//IETF//"..., 1024) = 216
write(1, "\"-//IETF//"..., 216) = 216

責任編輯：武曉燕來源：今日頭條

Strace 故障排除