I strace'd a java process that was triggering a lot of kernel time to see what syscalls were being used, and was surprised to see that gettimeofday()
and clock_gettime()
dominated (I suspect it's due to logging), which is strange considering that man vdso
states:
When tracing systems calls with strace(1), symbols (system calls) that are exported by the vDSO will not appear in the trace output.
How come these system calls are happening? Is there a way to avoid them?
The machine is running Ubuntu 16.04.1 on EC2.
To make things easier, I created a minimal test program in C (testgtod.c
):
#include <stdlib.h>
#include <sys/time.h>
void main(void)
{
struct timeval tv;
for(int i = 0; i < 1000; i++) {
/* glibc wrapped, shouldn't actually syscall */
gettimeofday(&tv, NULL);
}
}
I then compiled and ran the program under strace: gcc testgtod.c -o testgtod && sudo strace ./testgtod
The output included a thousand calls to gettimeofday(), despite my expectation.
Things I tested to make sure I'm not seeing things:
Made sure the binary is a 64-bit elf using
file
ldd ./testgtod
to make sure vDSO is active:linux-vdso.so.1 => (0x00007ffcee25d000) libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f6f6e161000) /lib64/ld-linux-x86-64.so.2 (0x0000559ed71f3000)
getauxval(AT_SYSINFO_EHDR) != NULL
Replaced
gettimeofday(&tv, NULL)
calls withsyscall(SYS_gettimeofday, &tv, NULL)
, increased number of calls to 10 million, ran undertime
- runtime behavior was the same in both cases:./testgtod 0.16s user 0.83s system 99% cpu 0.998 total
.