c++ - strace时间戳的含义

Question

当使用strace -T -tt -o outputfile myprogram时，输出如下

16:14:37.576804 write(1, "EFFEEFFFEFFGGEEFEEFECEEDB"..., 4096) = 4096 <0.000014>
16:14:37.577121 write(1, ",...,,,.\tDEDEEDEDEEBDEEFECECFBEE"..., 4096) = 4096 <0.000015>
16:14:37.577434 write(1, "66098\tT\t41\t....,.....,,,.,,,,..."..., 4096) = 4096 <0.000016>

第一列是系统调用的开始时间还是结束时间？如给定-T，最后一列给出为“显示系统调用所花费的时间。这记录了每个系统调用开始和结束之间的时间差。”为什么它与两次写入调用之间的时间间隔不同？作为前两个，16:14:37.577121 - 16:14:37.576804=0.000317 > 0.000014。

Answer 1

根据我刚刚试过的一个实验:

strace -t sleep 2

时间戳是系统调用开始的时间。 (它显示了一个 nanosleep，其时间戳与前面的系统调用匹配，而不是 2 秒后的时间戳。)

我不能肯定地说时间上没有一些测量不准确，但你不能指望在系统调用中花费的时间与时间戳的差异完全相同 - 你的过程必须做一些在系统调用之间的用户空间中工作。