Runtime discrepancy clock_gettime + funcition instrumentation

[Christian Weiss <Christian.Weiss@EMEA.NEC.COM>]

Dear all,

I made the following observation which I cannot explain. Maybe you can help me out?

I create a library which contains __cyg_profile_func_enter/exit hooks for function instrumentation.  I link this library to program which calls a dummy function a large number of times and measure the execution time. The resulting runtime differs significantly depending on whether I use the "-static" flag or not.

In detail:

Libtime.c:

#include <time.h>
void __cyg_profile_func_enter (void *func, void *caller) {
   struct timespec local_time;
   clock_gettime(CLOCK_MONOTONIC, &local_time);
}
void __cyg_profile_func_exit (void *func, void *caller) {
   struct timespec local_time;
   clock_gettime(CLOCK_MONOTONIC, &local_time);
}

Building a static and a shared library:

gcc -c libtime.c -o libtime.o
ar rcs libtime_gcc.a libtime.o
gcc -c -fPIC libtime.c -o libtime.o
gcc -shared -o libtime_gcc.so libtime.o
The test code test.c:

#include <stdio.h>
#include <stdlib.h>
#define N_ITER_DEFAULT 1000
long long func_1 (long long x) {
  return x;
}
int main (int argc, char *argv[]) {
  long long n_iter = argc > 1 ? atol (argv[1]) : N_ITER_DEFAULT;
  long long sum = 0;
  for (long long  i = 0; i < n_iter; i++) {
     sum += func_1(i);
  }
  printf ("sum: %lld\n", sum);
}

Building:

gcc -std=gnu99 -finstrument-functions -static test.c -o test_time_static_gcc.x -L. -ltime_gcc
gcc -std=gnu99 -finstrument-functions test.c -o test_time_dyn_gcc.x -L. -ltime_gcc

I made sure that the correct library is loaded to the dynamic binary at runtime:

[cweiss@amd022 overhead]$ ldd test_time_dyn_gcc.x  | grep libtime
      libtime_gcc.so => /home/cweiss/Vftrace_examples/overhead/libtime_gcc.so (0x00007fad0d42a000)
Measuring the runtime, the static binary takes about five times more time to finish than the dynamic one. I do not yet understand this observation:

[cweiss@amd022 overhead]$ time ./test_time_static_gcc.x 10000000
sum: 49999995000000
real         0m2.594s
user        0m0.396s
sys           0m2.197s
[cweiss@amd022 overhead]$ time ./test_time_dyn_gcc.x 10000000
sum: 49999995000000

real         0m0.518s
user        0m0.515s
sys           0m0.002s
Further remarks:


-          Libc version: 2.17

-          Gcc version: 8.20.

-          OS: CentOS  7.8

-          The issue does not appear when libtime is included explicitly and the "-static" flag is not used. This makes sense because then libc is linked dynamically.

-          A perf profile shows that the number of failed branch predictions is significantly higher in the static version (20 million (13.34%) vs 4000 (0%)),

Best regards,
Christian Weiss

Dr. Christian Weiss
Benchmark Analyst
Tel: +49 211 5369 126

NEC Deutschland GmbH
Geschäftsführer  Yuichi Kojima
Handelsregister Düsseldorf HRB 57941; VAT ID DE129424743