Re: [PATCH v4.16-rc5 (2)] x86/vdso: VDSO should handle clock_gettime(CLOCK_MONOTONIC_RAW) without syscall
From: Jason Vas Dias
Date: Sat Mar 17 2018 - 19:43:51 EST
fixed typo in timer_latency.c affecting only -r <repeat> printout
:
$ gcc -DN_SAMPLES=1000 -o timer timer_latency.c
CLOCK_MONOTONIC ( using rdtscp_ordered() ) :
$ ./timer -m -r 10
sum: 67615
Total time: 0.000067615S - Average Latency: 0.000000067S N zero
deltas: 0 N inconsistent deltas: 0
sum: 51858
Total time: 0.000051858S - Average Latency: 0.000000051S N zero
deltas: 0 N inconsistent deltas: 0
sum: 51742
Total time: 0.000051742S - Average Latency: 0.000000051S N zero
deltas: 0 N inconsistent deltas: 0
sum: 51944
Total time: 0.000051944S - Average Latency: 0.000000051S N zero
deltas: 0 N inconsistent deltas: 0
sum: 51838
Total time: 0.000051838S - Average Latency: 0.000000051S N zero
deltas: 0 N inconsistent deltas: 0
sum: 52397
Total time: 0.000052397S - Average Latency: 0.000000052S N zero
deltas: 0 N inconsistent deltas: 0
sum: 52428
Total time: 0.000052428S - Average Latency: 0.000000052S N zero
deltas: 0 N inconsistent deltas: 0
sum: 52135
Total time: 0.000052135S - Average Latency: 0.000000052S N zero
deltas: 0 N inconsistent deltas: 0
sum: 52145
Total time: 0.000052145S - Average Latency: 0.000000052S N zero
deltas: 0 N inconsistent deltas: 0
sum: 53116
Total time: 0.000053116S - Average Latency: 0.000000053S N zero
deltas: 0 N inconsistent deltas: 0
Average of 10 average latencies of 1000 samples : 0.000000053S
CLOCK_MONOTONIC_RAW ( using rdtscp() ) :
$ ./timer -r 10
sum: 25755
Total time: 0.000025755S - Average Latency: 0.000000025S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21614
Total time: 0.000021614S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21616
Total time: 0.000021616S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21610
Total time: 0.000021610S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21619
Total time: 0.000021619S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21617
Total time: 0.000021617S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 21610
Total time: 0.000021610S - Average Latency: 0.000000021S N zero
deltas: 0 N inconsistent deltas: 0
sum: 16940
Total time: 0.000016940S - Average Latency: 0.000000016S N zero
deltas: 0 N inconsistent deltas: 0
sum: 16939
Total time: 0.000016939S - Average Latency: 0.000000016S N zero
deltas: 0 N inconsistent deltas: 0
sum: 16943
Total time: 0.000016943S - Average Latency: 0.000000016S N zero
deltas: 0 N inconsistent deltas: 0
Average of 10 average latencies of 1000 samples : 0.000000019S
/*
* Program to measure high-res timer latency.
*
*/
#include <stdint.h>
#include <stdbool.h>
#include <sys/types.h>
#include <unistd.h>
#include <time.h>
#include <errno.h>
#include <alloca.h>
#include <string.h>
#include <stdio.h>
#include <stdlib.h>
#ifndef N_SAMPLES
#define N_SAMPLES 100
#endif
#define _STR(_S_) #_S_
#define STR(_S_) _STR(_S_)
#define TS2NS(_TS_) ((((unsigned long long)(_TS_).tv_sec)*1000000000ULL) + (((unsigned long long)((_TS_).tv_nsec))))
int main(int argc, char *const* argv, char *const* envp)
{ struct timespec sample[N_SAMPLES+1];
unsigned int cnt=N_SAMPLES, s=0 , avg_n=0;
unsigned long long
deltas [ N_SAMPLES ]
, t1, t2, sum=0, zd=0, ic=0, d
, t_start, avg_ns, *avgs=0;
clockid_t clk = CLOCK_MONOTONIC_RAW;
bool do_dump = false;
int argn=1, repeat=1;
for(; argn < argc; argn+=1)
if( argv[argn] != NULL )
if( *(argv[argn]) == '-')
switch( *(argv[argn]+1) )
{ case 'm':
case 'M':
clk = CLOCK_MONOTONIC;
break;
case 'd':
case 'D':
do_dump = true;
break;
case 'r':
case 'R':
if( (argn < argc) && (argv[argn+1] != NULL))
repeat = atoi(argv[argn+=1]);
break;
case '?':
case 'h':
case 'u':
case 'U':
case 'H':
fprintf(stderr,"Usage: timer_latency [\n\t-m : use CLOCK_MONOTONIC clock (not CLOCK_MONOTONIC_RAW)\n\t-d : dump timespec contents. N_SAMPLES: " STR(N_SAMPLES) "\n\t"
"-r <repeat count>\n]\t"
"Calculates average timer latency (minimum time that can be measured) over N_SAMPLES.\n"
);
return 0;
}
if( repeat > 1 )
{ avgs=alloca(sizeof(unsigned long long) * (N_SAMPLES + 1));
if( ((unsigned long) avgs) & 7 )
avgs = ((unsigned long long*)(((unsigned char*)avgs)+(8-((unsigned long) avgs) & 7)));
}
do {
cnt=N_SAMPLES;
s=0;
do
{ if( 0 != clock_gettime(clk, &sample[s++]) )
{ fprintf(stderr,"oops, clock_gettime() failed: %d: '%s'.\n", errno, strerror(errno));
return 1;
}
}while( --cnt );
clock_gettime(clk, &sample[s]);
for(s=1; s < (N_SAMPLES+1); s+=1)
{ t1 = TS2NS(sample[s-1]);
t2 = TS2NS(sample[s]);
if ( (t1 > t2)
||(sample[s-1].tv_sec > sample[s].tv_sec)
||((sample[s-1].tv_sec == sample[s].tv_sec)
&&(sample[s-1].tv_nsec > sample[s].tv_nsec)
)
)
{ fprintf(stderr,"Inconsistency: %llu %llu %lu.%lu %lu.%lu\n", t1 , t2
, sample[s-1].tv_sec, sample[s-1].tv_nsec
, sample[s].tv_sec, sample[s].tv_nsec
);
ic+=1;
continue;
}
d = t2 - t1;
if ( d == 0 )
{ zd += 1;
}
deltas[s-1] = d;
if(do_dump)
fprintf(stderr, "%lu %lu %llu\n",
sample[s].tv_sec, sample[s].tv_nsec, d
);
}
for(s = 0, sum=0; s < N_SAMPLES; s+=1)
sum += deltas[s];
fprintf(stderr,"sum: %llu\n",sum);
avg_ns = sum / N_SAMPLES;
t_start = TS2NS(sample[0]);
t1=(t2 - t_start);
printf("Total time: %1.1llu.%9.9lluS - Average Latency: %1.1llu.%9.9lluS N zero deltas: %u N inconsistent deltas: %u\n",
t1 / 1000000000, t1 % 1000000000,
avg_ns / 1000000000, avg_ns % 1000000000 ,
zd, ic
);
if (avgs != ((void*)0UL))
{ avgs[avg_n++] = avg_ns;
}
} while (--repeat);
if (avgs != ((void*)0UL))
{ for( s=0, sum=0; s < avg_n; s+=1)
sum += avgs[s];
printf("Average of %u average latencies of " STR(N_SAMPLES) " samples : %1.1llu.%9.9lluS\n"
, avg_n, (sum / 1000000000LLU)/avg_n, (sum % 1000000000LLU)/avg_n
);
}
return 0;
}