使用 ltrace 計時系統呼叫:添加 syscall
+ clock_gettime
?
我正在尋找系統呼叫方面的一些清晰度。我嘗試通過直接呼叫系統呼叫來避免 vDSO
clock_gettime
。這是一個名為sys_clock_gettime
.int clock = CLOCK_MONOTONIC; struct timespec ts; if (syscall(__NR_clock_gettime, clock, &ts) == -1){ exit(-1); }
該程序採用時鐘的名稱(
CLOCK_BOOTTIME, CLOCK_MONOTONIC
等…)和要進行的許多呼叫。例如,下面的程式碼片段將呼叫 100 次clock_gettime
時鐘CLOCK_BOOTTIME
。./sys_clock_gettime CLOCK_BOOTTIME 100
我試圖
ltrace
弄清楚發生了什麼:ltrace -cS ./sys_clock_gettime CLOCK_BOOTTIME 100 % time seconds usecs/call calls function ------ ----------- ----------- --------- -------------------- 77.41 0.006887 68 100 syscall 14.32 0.001274 12 100 clock_gettime 1.79 0.000159 159 1 brk 1.17 0.000104 104 1 exit 1.16 0.000103 51 2 strcmp 0.82 0.000073 14 5 mmap 0.65 0.000058 14 4 mprotect 0.61 0.000054 54 1 exit_group 0.51 0.000045 45 1 atoi 0.31 0.000028 14 2 openat 0.30 0.000027 13 2 fstat 0.29 0.000026 13 2 close 0.19 0.000017 17 1 munmap 0.17 0.000015 15 1 access 0.16 0.000014 14 1 read 0.15 0.000013 13 1 arch_prctl ------ ----------- ----------- --------- -------------------- 100.00 0.008897 225 total
出於某種原因,有一個
syscall
條目和一個clock_gettime
條目。您可以說這syscall
是一個庫條目,clock_gettime
而是一個系統呼叫條目,因為如果您禁用其中的-S
模式,ltrace
它將不會顯示。如果我對系統呼叫的執行時間感興趣,我應該添加syscall
和clock_gettime
資訊嗎?出於某種原因,這只發生在我在 Amazon Linux 2 中執行它時,在我自己的電腦上的 Ubuntu VM 中執行時,我只得到一個SYS_clock_gettime
條目,正如我所期望的那樣。現在,將它與另一個程序進行比較,我們稱之為它
vdso_clock_gettime
,它採用相同的參數。ltrace -cS ./vdso_clock_gettime CLOCK_BOOTTIME 100 % time seconds usecs/call calls function ------ ----------- ----------- --------- -------------------- 85.82 0.004340 43 100 clock_gettime 3.08 0.000156 156 1 brk 2.02 0.000102 51 2 strcmp 1.90 0.000096 96 1 exit 1.38 0.000070 14 5 mmap 1.13 0.000057 14 4 mprotect 0.97 0.000049 49 1 exit_group 0.93 0.000047 47 1 atoi 0.59 0.000030 15 2 openat 0.51 0.000026 13 2 fstat 0.51 0.000026 13 2 close 0.32 0.000016 16 1 access 0.32 0.000016 16 1 munmap 0.26 0.000013 13 1 read 0.26 0.000013 13 1 arch_prctl ------ ----------- ----------- --------- -------------------- 100.00 0.005057 125 total
如果我不從第一個程序的輸出中添加
syscall
和clock_gettime
條目,那麼呼叫系統呼叫所需的總時間clock_gettime
(12 微秒/呼叫)實際上比我在第二個中呼叫 vDSO 版本(43 微秒/呼叫)時要低程序。在我看來,這沒有任何意義。只有當第一個程序的呼叫需要大約 80 微秒/呼叫(添加兩個條目)時才有意義,因為 vDSO 應該加速這一點。我知道在這個系統(核心 5.10)中,
clock_gettime
是通過 vDSO 加速的,因為當我執行下面的程式碼片段時,我沒有得到任何輸出:strace -e clock_gettime,gettimeofday -- date >/dev/null +++ exited with 0 +++
我不確定這是否相關,但時鐘源設置為
tsc
. 關於這裡發生了什麼的任何想法?**編輯:**查看實際跟踪,我開始認為呼叫
syscall
包括兩者。syscall(228, 7, 0x7ffd270f9c80, 0x1999999999999999 <unfinished ...> clock_gettime@SYS(7, 0x7ffd270f9c80, 0x1999999999999999, 0x7ffd270fa70a) = 0 <... syscall resumed> )
我也嘗試過
nanosleep
,如果我同時計算syscall
和nanosleep
呼叫,睡眠時間會加倍,這沒有任何意義。我對麼?
我懷疑一些混亂歸結為命名。在我的系統上,強制系統呼叫會產生這種風格的跟踪:
% time seconds usecs/call calls function ------ ----------- ----------- --------- -------------------- 84.10 0.005402 54 100 syscall 10.14 0.000651 6 100 SYS_clock_gettime 1.87 0.000120 17 7 SYS_mmap 0.97 0.000062 62 1 SYS_brk 0.72 0.000046 11 4 SYS_mprotect 0.47 0.000030 30 1 SYS_access 0.45 0.000029 29 1 SYS_read 0.37 0.000024 12 2 SYS_fstat 0.31 0.000020 10 2 SYS_openat 0.26 0.000017 17 1 SYS_munmap 0.23 0.000015 7 2 SYS_close 0.11 0.000007 7 1 SYS_arch_prctl ------ ----------- ----------- --------- -------------------- 100.00 0.006423 222 total
使用 vDSO 會產生這種風格的跟踪:
% time seconds usecs/call calls function ------ ----------- ----------- --------- -------------------- 93.17 0.004158 41 100 clock_gettime 1.66 0.000074 74 1 SYS_access 1.61 0.000072 10 7 SYS_mmap 0.92 0.000041 10 4 SYS_mprotect 0.72 0.000032 16 2 SYS_openat 0.56 0.000025 25 1 SYS_brk 0.36 0.000016 8 2 SYS_close 0.34 0.000015 7 2 SYS_fstat 0.34 0.000015 15 1 SYS_munmap 0.18 0.000008 8 1 SYS_read 0.16 0.000007 7 1 SYS_arch_prctl ------ ----------- ----------- --------- -------------------- 100.00 0.004463 122 total
第一種情況,程序呼叫C庫
syscall
函式,該函式呼叫clock_gettime
系統呼叫;在第二種情況下,程序呼叫 C 庫clock_gettime
函式,該函式呼叫 vDSO。這兩個clock_gettime
呼叫不同,但它們在您的跟踪中顯示相同。據我了解,報告的時間
syscall
確實包括報告的時間SYS_clock_gettime
;這也意味著百分比顯示具有誤導性。這不在文件中,而且我還沒有閱讀所有原始碼,所以我可能錯了。要考慮的另一點是由
ltrace
includeltrace
的成本測量的時間。其他分析工具,例如perf stat
顯示 vDSO 確實更快:42.13 msec task-clock # 0.988 CPUs utilized 4 context-switches # 0.095 K/sec 0 cpu-migrations # 0.000 K/sec 44 page-faults # 0.001 M/sec 138,771,425 cycles # 3.294 GHz (71.53%) 38,690,379 instructions # 0.28 insn per cycle (71.57%) 7,599,904 branches # 180.377 M/sec (81.14%) 300,729 branch-misses # 3.96% of all branches (75.76%) 0.042636471 seconds time elapsed 0.015510000 seconds user 0.027143000 seconds sys
通常用於系統呼叫版本(超過 100,000 次呼叫),以及
4.84 msec task-clock # 0.815 CPUs utilized 0 context-switches # 0.000 K/sec 0 cpu-migrations # 0.000 K/sec 48 page-faults # 0.010 M/sec 6,257,648 cycles # 1.294 GHz (50.28%) 9,019,370 instructions # 1.44 insn per cycle 1,925,045 branches # 398.113 M/sec 1,594 branch-misses # 0.08% of all branches (49.72%) 0.005934008 seconds time elapsed 0.003025000 seconds user 0.003025000 seconds sys
對於 vDSO 版本。