Linux

解釋在 strace 上顯示的開放系統呼叫的時間

  • August 3, 2016

我們遇到了供應商應用程序的延遲問題。我執行了strace -Tttt這個過程並得到了這個:

[...]
1470166748.946144 open("/opt/app/shdbrth/X       ", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000016>
1470166800.850979 open("/opt/app/shdbrth/X38347", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 10 <0.000070>
1470166800.851139 fstat(10, {st_mode=S_IFREG|0660, st_size=0, ...}) = 0 <0.000006>
[...]

根據手冊頁-ttt每行的前綴是系統呼叫的時間。該-T選項將呼叫處理的時間附加在括號<之間。>但是,這似乎並沒有在上面的範例中加起來。

例如,第二行開始於 1,470,166,800 紀元秒和 850,979 微秒。根據附加的計時器,處理時間為 70 微秒。但是,下一行從相同的紀元秒和 851,139 微秒開始——相差 90 微秒。

我打算把它寫成成本,但也許有更準確的解釋。

行首的時間是核心開始處理該系統呼叫的時間。行尾的持續時間是核心開始處理該系統呼叫的時間與核心響應該系統呼叫的時間之間的時間間隔。

下一行開頭的時間是核心開始處理下一個系統呼叫的時間。在對一個系統呼叫的回復和進入下一個系統呼叫之間,發生了兩種事情:程序執行使用者程式碼,並且可能其他程序被調度在同一個處理器上。

在您的範例中,第一次open呼叫耗時 16µs,下一次呼叫大約在 12 秒後發出。在這 12 秒內,該程序執行使用者程式碼,並且可能多次被搶占以執行其他程序。在第二次open呼叫和隨後的之間fstat,大約經過了 90µs;鑑於這是多麼小,這表明該程序只執行了少量的使用者程式碼並且沒有被搶占。

引用自:https://unix.stackexchange.com/questions/299909