Re: [Fwd: Re: [patch] Real-Time Preemption, -RT-2.6.9-mm1-V0.4]

From: Florian Schmidt
Date: Sat Oct 30 2004 - 12:37:43 EST


On Sat, 30 Oct 2004 15:15:07 +0200
Ingo Molnar <mingo@xxxxxxx> wrote:

> should have mentioned that in the user-triggered modus you have to do
> the latency measurement in userspace. It is only the trace that is
> correct, for the time being. This trace shows what i'd expect a jackd
> wakeup to look like normally: 13 usecs.
>
> Ingo
>

Hi,

i thought, why not try to get jack out of the equation first and use a
different irq source. So i wrote a small test app for /dev/rtc to see if i
see the same erratic behaviour [.cc source file atached. find a small
tarball here: http://affenbande.org/~tapas/wakeup.tgz (it has a simple
makefile, plus a script which does the chrt thing to make it SCHED_FIFO)].

This program takes two parameters: the desired freq of the rtc and the
number of irq's to be measured.

Then it polls on the fd of /dev/rtc and takes a cpu cycle count timestamp as
soon as poll returns. At the end of the program i tried to gather some
[useful ???] statistics of the data:

- the mean difference in cycles between two wakeups

- the max difference in cycles between two wakeups (and how much this
differs from the mean difference)

- the min difference in cycles between two wakeups (and how much this
differs from the mean difference)

- the mean difference from the mean difference :)

And alas, wiggling windows screws up the timing on V0.5.6 for this, too.

dunno, if this is any useful to you, but i felt the urge to try it :)

flo


P.S.: don't forget to make your rtc irq SCHED_FIFO with a high priority, too

here's a sample output with window wiggling in X (rt_wakeup runs chrt -f 90
wakeup, so make rtc at least prio 91):

~/source/my_projects/wakeup$ ./rt_wakeup 1024 6000
freq: 1024 #: 6000
setting up /dev/rtc...
locking memory...
turning irq on, beginning measurement (might take a while)...
...measurement done

mean cycle difference betweem two wakeups: 1.17845e+06 cycles

min. cycle difference betweem two wakeups: 185992 cycles (#: 1563)
diff from mean diff: 992461

max. cycle difference betweem two wakeups: 9.73166e+06 cycles (#: 1546)
diff from mean diff: 8.5532e+06
^this is bad i suppose :)

mean difference from mean difference: 25279.2 cycles


here's one on a rather idle system:

~/source/my_projects/wakeup$ ./rt_wakeup 1024 6000
freq: 1024 #: 6000
setting up /dev/rtc...
locking memory...
turning irq on, beginning measurement (might take a while)...
...measurement done

mean cycle difference betweem two wakeups: 1.16697e+06 cycles

min. cycle difference betweem two wakeups: 1.1486e+06 cycles (#: 5492)
diff from mean diff: 18379.2

max. cycle difference betweem two wakeups: 1.18439e+06 cycles (#: 5491)
diff from mean diff: 17417.8

mean difference from mean difference: 1144.82 cycles
~/source/my_projects/wakeup$
#include <iostream>
#include <sstream>
#include <string>

#include <linux/rtc.h>
#include <sys/ioctl.h>
#include <sys/time.h>
#include <sys/types.h>
#include <sys/mman.h>
#include <fcntl.h>
#include <errno.h>
#include <unistd.h>
#include <poll.h>

#include <cmath>

// this program is partly ripped off the rtc docs in the linux kernel source tree

// the cycle count count ripped from jackd
typedef unsigned long long cycles_t;

extern cycles_t cacheflush_time;

#define rdtscll(val) \
__asm__ __volatile__("rdtsc" : "=A" (val))

static inline cycles_t get_cycles (void)
{
unsigned long long ret;

rdtscll(ret);
return ret;
}



int main(int argc, char *argv[]) {
if (argc < 3) {
std::cout << "usage: wakeup [freqency(hz)] [number of interrupts]" << std::endl;
}

std::stringstream args;
args << argv[1] << " " << argv[2];

int freq;
args >> freq;

int number;
args >> number;

std::cout << "freq: " << freq << " #: " << number << std::endl;

if (number < 3) {
std::cout << "number of irq's must be >= 3" << std::endl;
return(0);
}

// an array to store the cycles for each interrupt in.
cycles_t *cycles = new cycles_t[number];

std::cout << "setting up /dev/rtc..." << std::endl;

int fd;
fd = open("/dev/rtc", O_RDONLY);
if (fd == -1) {
perror("/dev/rtc");
exit(errno);
}

int retval = ioctl(fd, RTC_IRQP_SET, freq);
if (retval == -1) {
perror("ioctl");
exit(errno);
}


// we poll only on a single descriptor, the /dev/rtc one
struct pollfd fds[1];
pollfd pfd;
pfd.fd = fd;
pfd.events = POLLRDNORM|POLLRDBAND;
fds[0] = pfd;


// we set the timeout to 8 periods
int timeout;
timeout = 8*( (int)( (1.0f/(float)freq)*1000.0f ) );

std::cout << "locking memory..." << std::endl;
mlockall(MCL_CURRENT);
// std::cout << "sleeping 1 sec" << std::endl;
// sleep(1);

std::cout << "turning irq on, beginning measurement (might take a while)..." << std::endl;

retval = ioctl(fd, RTC_PIE_ON, 0);
if (retval == -1) {
perror("ioctl");
exit(errno);
}

unsigned long data;
for (int i = 0; i < number; ++i) {
// first we poll, until data is available
retval = poll(fds, 1, timeout);
if (retval == -1) {
perror("poll");
exit(errno);
}

// then we take a timestamp;
cycles[i] = get_cycles();
// std::cout << "irq!" << std::endl;

// then we read it
retval = read(fd, &data, sizeof(unsigned long));
if (retval == -1) {
perror("read");
exit(errno);
}

// see if the high bytes of the data contains a number of irq > 1. probably wrong,
data = (data >> 16);
if (data > 1) {std::cout << "more than 1 irq happened inbetween this and last wakeup" << std::endl;}
}


std::cout << "...measurement done" << std::endl;

// first one is often skewed
double mean_diff = ((double)cycles[number-1] - (double)cycles[1])/(double)(number-2);

// std::cout << "0: \t" << cycles[0] << std::endl;
double min_diff, max_diff;
min_diff = max_diff = (double)(cycles[2] - cycles[1]);

unsigned int min_diff_i, max_diff_i;
min_diff_i = max_diff_i = 2;

double mean_diff_diff = 0;

for (int i = 2; i < number; ++i) {
double diff = (double)(cycles[i] - cycles[i-1]);
if (diff < min_diff) {min_diff = diff; min_diff_i = i;}
if (diff > max_diff) {max_diff = diff; max_diff_i = i;}

mean_diff_diff += fabs(mean_diff - diff);
// std::cout << i << ": \t" << cycles[i] << std::endl;
}
mean_diff_diff /= (double)(number - 2);

std::cout << std::endl << "mean cycle difference betweem two wakeups: "
<< mean_diff
<< " cycles" << std::endl << std::endl;

std::cout << "min. cycle difference betweem two wakeups: "
<< min_diff << " cycles (#: " << min_diff_i << ") \n diff from mean diff: "
<< fabs(min_diff - mean_diff) << std::endl << std::endl;

std::cout << "max. cycle difference betweem two wakeups: "
<< max_diff << " cycles (#: " << max_diff_i << ") \n diff from mean diff: "
<< fabs(max_diff - mean_diff) << std::endl << std::endl;

std::cout << "mean difference from mean difference: "
<< mean_diff_diff << " cycles" << std::endl;

// return success
close(fd);
return 1;
}