為什麼strace
不顯示這個過程正在等待什麼?
強者
strace
讓我失望了。這怎麼可能?
time foo
顯示foo
執行需要幾秒鐘(“真實”),但在使用者空間(“使用者”)和核心(“系統”)中使用的 CPU 時間可以忽略不計。對於好奇的,foo
定義如下。所以它大部分時間都在等待其他事情,而不是執行 CPU 指令。通常,我可以看到它是如何等待的
strace
——即什麼系統呼叫被阻塞了很長一段時間。不幸的是,這種方法沒有奏效。
strace -ttt -T -C -w foo
顯示系統呼叫、時間戳以及系統呼叫所花費的(實際)時間的摘要。但是這個特定的過程顯示為在系統呼叫中花費的整體(實時)時間可以忽略不計。
foo
實際上是journalctl -b -u dev-hugepages.mount
。除了我每次都必須將最後一個參數更改為不同的 systemd 單元才能重現它。換句話說,我正在調查的延遲發生在我第一次嘗試獲取任何一個 systemd 單元的日誌時。 編輯:在回答了主要問題之後,我也意識到我在重現延遲時遇到這個問題的原因。這個過程花費的時間是一個特定的問題,顯然它不會發生在所有系統上。https://github.com/systemd/systemd/issues/7963
遇到此問題的通常原因是程序在頁面錯誤中阻塞。這些是通過記憶體映射 aka 執行的對文件的讀取或可能寫入
mmap()
。您可能已經mmap()
在系統呼叫的跟踪中註意到了一些。如果您使用的是該
/usr/bin/time
程序而不是time
內置的 shell,您可能還會注意到:0.04user 0.10system 0:02.29elapsed 6%CPU (0avgtext+0avgdata 40464maxresident)k 73632inputs+0outputs (376major+1081minor)pagefaults 0swaps
major
pagefaults 是需要文件系統 IO 的。minor
頁面錯誤的重要性要小得多(可能只是“TLB 未命中”)。我懷疑
inputs
是閱讀的總頁數。目前,我認為文件映射頁面總是相同的大小。大多數情況下為 4096 字節,但您可以檢查getconf PAGESIZE
.所以這代表約 290 兆字節,以每秒超過 100 兆字節的速度讀取,這是像我這樣的硬碟的標準速度。謎團已揭開!
另請注意,您假設您有一個完整的空閒 CPU 用於此過程。否則,程序可能會被阻塞,等待其他程序讓出 CPU。
strace
僅顯示程序由於系統呼叫而進入(然後離開)核心的時間。或者當傳遞一個unix信號時。但是,還有其他類型的中斷strace
根本不顯示。所以這些包括
- 頁面錯誤。
- 定時器中斷。這用於在目前程序耗盡其在 CPU 上分配的時間片時切換到不同的程序。