Re: time warps, I despair

Ingo Molnar (mingo@pc5829.hil.siemens.at)
Mon, 4 Nov 1996 17:08:15 +0100 (MET)


On Mon, 4 Nov 1996, Ulrich Windl wrote:

> Maybe Linus can change the cli/sti macros for 2.1 to produce a syslog
> message if interrupts are delayed for a significant time...

huh dont do that. It slows down the kernel noticeably. And increases the
size too, by quite alot.

I've attached a user-space testprogram that tests for time irregularities,
using the Pentium timestamp counter as reference timer. Lost jiffies are
detected by this program for example.

usage: anomaly <number of iterations> <timing error treshold in clocks>

'anomaly 10000 100' produces this output on my system:

YIKES, time warp: 2627606054007 -530.292287
YIKES, time warp: 2627606054431 -554.299056
YIKES, time warp: 2627606055700 -523.321055
YIKES, time warp: 2627606056132 -555.327823
[...]

500 cycles errors are of course not time warps ... running this program
over a larger period of time and with a treshold of 10000 doesnt show up
any irregularities on my system :( [10000 means 100 usecs treshold!].

The program fits a linear on tighly sampled curve and does a second pass
to find out about irregularieties, and prints them if they exceed the
treshold. The code is in an infinit loop, the number of iteration
specifies the number of samples per curve fitting. [the value of 10000
i've used is reasonable].

To detect 1 millisec irregularities, you should type [on a 100MHz system]:

anomaly 10000 100000

and you should let this run for a larger period of time. The code detects
if the user-space program gets interrupted by interrupts, so this program
is >very< accurate.

The code detects 'local' anomalies as well, not only 'global' anomalies,
so i would be really interested what you get from running this code.

Ingo

[comments and bug reports are welcome!]

----------------- anomaly.c starts in the next line ---------------->

#include <stdlib.h>
#include <stdio.h>
#include <unistd.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <assert.h>

#define RTSC(x) __asm__ __volatile__ ( ".byte 0x0f,0x31" \
:"=a" (((unsigned long*)&x)[0]), \
"=d" (((unsigned long*)&x)[1]))

void get_unsafe_usecs( unsigned long long * bus_clocks, unsigned long long * xtime )
{
struct timeval tv;

gettimeofday(&tv,0);
*xtime=tv.tv_sec*1000000+tv.tv_usec;

RTSC(*bus_clocks);
}

void get_safe_usecs( unsigned long long * bus_clocks, unsigned long long * xtime )
{
unsigned long long t1,t2;

do {
RTSC(t1);
get_unsafe_usecs( bus_clocks, xtime );
RTSC(t2);
} while ( t2-t1 > 1000 );
}

int main( int argc, char * * argv )
{
unsigned long long *bus, *xtime;
unsigned long long sum_xtime_even;
unsigned long long sum_xtime_uneven;
unsigned long long sum_bus_even;
unsigned long long sum_bus_uneven;
int i,N,treshold;
long double quotient,offset;
unsigned long long bus1,bus2,xtime1,xtime2;

if( argc != 3 ) {
printf("usage: anomaly <number of iterations> <timing treshold in cycles>\n");
exit(-1);
}

N=atol(argv[1]);
treshold=atol(argv[2]);

if( N<1 || N>1000000 ) {
printf("number of iterations incorrect [should be between 1 and 1M]\n");
exit(-1);
}

if( N<1 || N>1000000000 ) {
printf("treshold is incorrect [should be between 1 and 1G]\n");
exit(-1);
}

bus=malloc(sizeof(long long)*N);
xtime=malloc(sizeof(long long)*N);

assert( bus && xtime );

for(;;) {

for( i=0; i<N; i++ ) {
get_safe_usecs( bus+i, xtime+i );
}

sum_bus_even=0;
sum_xtime_even=0;
for( i=0; i<N/2; i++ ) {
sum_bus_even+=*(bus+i);
sum_xtime_even+=*(xtime+i);
}

sum_bus_uneven=0;
sum_xtime_uneven=0;
for( i=0; i<N/2; i++ ) {
sum_bus_uneven+=*(bus+i+N/2);
sum_xtime_uneven+=*(xtime+i+N/2);
}

bus1 = sum_bus_even;
xtime1 = sum_xtime_even;

bus2 = sum_bus_uneven;
xtime2 = sum_xtime_uneven;

quotient = ((long double)(bus2-bus1))/((long double)(xtime2-xtime1));
offset = ((long double)bus2-(long double)(xtime2)*quotient)/(long double)N*2.0;

for( i=0; i<N; i++ ) {
long double delta;

delta= ((long double)(*(xtime+i)))*quotient + offset - (*(bus+i));
if( abs(delta) > treshold )
printf("YIKES, time warp: %Lu %Lf\n",*(bus+i),delta);
}

}

return(0);
}