Tracing using ltrace and strace

Basically, a reprint from https://blog.packagecloud.io/eng/2017/03/08/system-calls-are-much-slower-on-ec2/

To avoid the cost of usual syscall, gettimeofday is implemented as virtual Dynamic Shared Object (vDSO). On my box, according to the output of strace and ltrace, we know that gettimeofday doesn’t amount to a syscall anymore.

1
2
3
4
5
6
7
8
9
10
11
12
13
#include <stdio.h>
#include <stdlib.h>
#include <sys/time.h>

int main(int argc, char *argv[])
{

struct timeval tv;
for (int i=0; i<100; i++) {
gettimeofday(&tv,NULL);
}

return 0;
}
1
$ clang test.c && strace -c ./a.out
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         1           read
  0.00    0.000000           0         2           open
  0.00    0.000000           0         2           close
  0.00    0.000000           0         2           fstat
  0.00    0.000000           0         7           mmap
  0.00    0.000000           0         4           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         1           brk
  0.00    0.000000           0         3         3 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                    25         3 total

Similarly, we can use ltrace as well:

1
$ clang test.c && ltrace -cS ./a.out
% time     seconds  usecs/call     calls      function
------ ----------- ----------- --------- --------------------
 97.10    0.006057          60       100 gettimeofday
  0.85    0.000053           7         7 SYS_mmap
  0.56    0.000035           8         4 SYS_mprotect
  0.32    0.000020           6         3 SYS_access
  0.26    0.000016           8         2 SYS_open
  0.22    0.000014          14         1 SYS_munmap
  0.19    0.000012           6         2 SYS_fstat
  0.19    0.000012           6         2 SYS_close
  0.11    0.000007           7         1 SYS_read
  0.11    0.000007           7         1 SYS_brk
  0.08    0.000005           5         1 SYS_arch_prctl
------ ----------- ----------- --------- --------------------
100.00    0.006238                   124 total