I have got results for strace -c
on RHEL 7 and RHEL 6
for this command:
strace -c /bin/sleep 20
and I don’t understand why the seconds
column for nanosleep
is equal to 0. I had expected it to be 20.
0.00 0.000000 0 1 nanosleep
Here is a full strace report:
$ strace -c /bin/sleep 20 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000019 1 15 12 open 0.00 0.000000 0 1 read 0.00 0.000000 0 5 close 0.00 0.000000 0 8 6 stat 0.00 0.000000 0 3 fstat 0.00 0.000000 0 9 mmap 0.00 0.000000 0 3 mprotect 0.00 0.000000 0 1 munmap 0.00 0.000000 0 3 brk 0.00 0.000000 0 1 1 access 0.00 0.000000 0 1 nanosleep 0.00 0.000000 0 1 execve 0.00 0.000000 0 1 arch_prctl ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000019 52 19 total
And there is a call to nanosleep in a detailed report:
nanosleep({20, 0}, NULL) = 0
So seconds must be 20, not 0. What do you think?
Advertisement
Answer
From the manual page of strace(1):
-c
On Linux, this attempts to show system time (CPU time spent running in the kernel)
I think that:
when a process calls nanosleep(), it asks the kernel to be suspended for a period of time. The kernel sets up a few things (like some flag, a timer, a timestamp…), suspends the calling process, and goes to do something else. strace(1) reports the time spent by the kernel to do this, not the time the process stays suspended.
May be that this -c
strace option can be thought as “-cost”: how much time this syscall costs?