Posix Execution time clock

Hi,

My question might be a little basic for this list... Maybe someone could point me out to another forum :)

I'm trying to get some measures using the execution time clock in my system and I found some slight differences in the use of the CLOCK_THREAD_CPUTIME_ID and CLOCK_MONOTONIC clocks. The measures are between the same points of code. My concern is that, sometimes, the measure obtained with CLOCK_MONOTONIC is lower than using CLOCK_THREAD_CPUTIME_ID. Find below a dummy example to test this strange behavior.

It doesn't happen very often but the error could be around hundreds of microseconds.

So my question is: are both POSIX clocks based on different physical clocks? I always though they use the TSC...

My previous guess was that such behavior could be caused by the CPU frequency scaling but the same happened when I disabled it.

My system is running Linux 2.6.24-25-rt #1 SMP PREEMPT RT (Ubuntu package) and I run my tests using the affinity parameter to bind all the threads included in the test to the same CPU.

Thanks so much and great work

Hector

---

#include <time.h>
#include <pthread.h>
#include <float.h>

#include <string.h>
#include <stdio.h>
#include <stdlib.h>
#include <sys/mman.h>

#define THREAD_CLOCK CLOCK_THREAD_CPUTIME_ID
#define COMMON_CLOCK CLOCK_MONOTONIC

#define LAST_JOB 10000
#define PRIO_HIGH 90

#define MAX_SAFE_STACK (8*1024) /* The maximum stack size which is
guaranteed safe to access without faulting */

#define CHK(p) { int ret;                                      \
                if ((ret = p)) {                   \
                  printf ("Error:"#p":%s\n", strerror (ret)); \
                  exit (-1);                                  \
}                                             \

}

static int error_count = 0;

double timespec_to_double(const struct timespec *time) {
return time->tv_nsec*1E-9 + (double)time->tv_sec;
}

void double_to_timespec(double time, struct timespec *ts) {
ts->tv_sec = (long) time;
ts->tv_nsec = (long)((time - (double)ts->tv_sec) * 1E9);
}

void add_timespec (struct timespec *s,
const struct timespec *t1,
const struct timespec *t2)
{
s->tv_sec = t1->tv_sec + t2->tv_sec;
s->tv_nsec = t1->tv_nsec + t2->tv_nsec;
if (s->tv_nsec >= 1E9) {
s->tv_sec ++;
s->tv_nsec -= 1E9;
}
}

void incr_timespec (struct timespec *t1, const struct timespec *t2) {
t1->tv_sec += t2->tv_sec;
t1->tv_nsec += t2->tv_nsec;
if (t1->tv_nsec >= 1E9) {
t1->tv_sec ++;
t1->tv_nsec -= 1E9;
}
}

int smaller_or_equal_timespec (const struct timespec *t1,
const struct timespec *t2)
{
return t1->tv_sec < t2->tv_sec || (t1->tv_sec == t2->tv_sec &&

     t1->tv_nsec <= t2->tv_nsec);
}

int compare_times (float time, struct timespec* start, struct timespec* stop) {
double diff, start_time, stop_time = 0.0;

start_time = timespec_to_double (start);
stop_time = timespec_to_double (stop);

diff = stop_time - start_time;

if (time > diff)
{
++error_count;
printf ("\tError number %d: %7.6f microseconds\n", error_count,
(time-diff)*1E6);
}
return 0;
}

void stack_prefault(void) {

unsigned char dummy[MAX_SAFE_STACK];

memset(&dummy, 0, MAX_SAFE_STACK);
return;
}

int posix_linux_requirements (void) {
/* Lock memory */
if(mlockall(MCL_CURRENT|MCL_FUTURE) == -1) {
perror("mlockall failed");
return (-1);
}

/* Pre-fault our stack */
stack_prefault ();

return 0;
}

void eat (float for_seconds)
{
struct timespec now, temp, end;

clock_gettime (THREAD_CLOCK, &now);

double_to_timespec (for_seconds, &temp);
add_timespec (&end, &now, &temp);

do {
clock_gettime(THREAD_CLOCK, &now);
}
while ( smaller_or_equal_timespec (&now, &end) );
}

int main (int argc, char *argv[])
{
// Execution Time
float time = 9E-4; //900 microseconds
struct timespec period = {0, 1.8E6}; // 1.8 milliseconds struct sched_param param_rt;
struct timespec next_activation, start_time, stop_time; int count = 0;

// Change policy to SCHED_FIFO and priority to main thread param_rt.sched_priority = PRIO_HIGH;
//CHK ( pthread_setschedparam (pthread_self(), SCHED_FIFO, &param_rt) ); CHK ( sched_setscheduler (0, SCHED_FIFO, &param_rt) );

// Set Linux RT-PREEMPT requirements
CHK ( posix_linux_requirements () );

CHK ( clock_gettime(COMMON_CLOCK, &next_activation) );

for (count = 0; count < LAST_JOB; count++)
{

CHK (clock_nanosleep(COMMON_CLOCK, TIMER_ABSTIME,

                      &next_activation, NULL));

CHK ( clock_gettime(COMMON_CLOCK, &start_time) ); // Do job: execution time clock
eat (time);
CHK ( clock_gettime(COMMON_CLOCK, &stop_time) ); CHK ( compare_times (time, &start_time, &stop_time) ); // Compute next activation
incr_timespec (&next_activation, &period);
}
printf ("\nEnd of test\n");
return 0;
}

Hi Hector,

I'm not the expert here, but the experts might ask you to reproduce on a vanilla rt kernel. (I'm sure the question will contain the word "crap" :-)

Best regards
Uwe

Pengutronix e.K.                              | Uwe Kleine-König            |
Industrial Linux Solutions                    | http://www.pengutronix.de/  |
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Check the dmesg logs for hints on TSC. There are some TSCs that are not used as clocksources because they are out-of-sync between CPUs, because they halt on idle, because they halt on inner C-states and so on...

How many CPUs?

NOTE for SMP systems
The CLOCK_PROCESS_CPUTIME_ID and CLOCK_THREAD_CPUTIME_ID clocks are realized on many platforms using timers from the CPUs (TSC on i386, AR.ITC on Itanium). These registers may differ between CPUs and as a consequence these clocks may return bogus results if a process is migrated to another CPU.

By definition, CLOCK_MONOTONIC seems to be what you want.

Another interesting detail is that you have to check what is the value of /proc/sys/kernel/vsyscall64 for it constrols the behavior and resolution of clock reads (enabling or disabling VDSO clock enhancements). Try setting it to zero and repeating your tests.

Along with that, the latest version for 2.6.24, IIRC, was 2.6.24.7-rt27. So, it sounds like you are using older versions of old software.

Regards,
Luis

[ Luis Claudio R. Goncalves                    Bass - Gospel - RT ]
[ Fingerprint: 4FDD B8C4 3C59 34BD 8BE9  2696 7203 D980 A448 C8F8 ]

Hi again,

Thanks for your really quick replies and your contributions! I have found some interesting info:

My dmesg output:

   [    8.333748] checking TSC synchronization [CPU#0 -> CPU#1]:
   [    8.353732] Measured 3359526540 cycles TSC warp between CPUs, 
turning off TSC clock.
   [    8.353737] Marking TSC unstable due to: check_tsc_sync_source 

failed.

So my system is not using the TSC...

A DualCore.

Yeah, I have check the available clocks in /sys/devices/system/clocksource/clocksource0/available_clocksource

and the clock used according to cat /sys/devices/system/clocksource/clocksource0/current_clocksource

I have switched to acpi_pm but the same issue exists. I have also disabled one CPU in the BIOS to use the TSC... I though it could be good try but... useless

No, I actually need the CLOCK_THREAD_CPUTIME_ID. Basically I have to get some execution times measures to perform the schedulability analysis. But I have found this strange behavior and I just wonder why.

That functionality is only for 64bits, isn't it? My computer is still 32 bits... :)

Please let me know any new suggestion...

Regards,

Hector

--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

The version scheme of Ubuntu doesn't allow to read the used rt patch from the kernel version. The Ubuntu version used is 2.6.24-25-rt. This only means something like: The 25th Ubuntu revision of the 2.6.24 kernel in the rt feature set.

Best regards
Uwe

Pengutronix e.K.                              | Uwe Kleine-König            |
Industrial Linux Solutions                    | http://www.pengutronix.de/  |
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Hi all,

Just to complete the info. I have repeated a similar test (SMP and scaling frequency disabled in the BIOS, TSC clock) with another function:

If I measure the attached function with CLOCK_THREAD_CPUTIME_ID, I keep getting variable timing results. The execution of this function takes about 400 usecs in my system. Having called it more than 10_000 times, most of the measures are within 100 usecs from this value. This range makes sense to me. But I have found a few measures (less than 10 out of 10_000) which are over 1100 usecs, which it's a bit suspicious. Since this clock just takes the execution time associated to a single thread (no preemption time should be included) and the function's execution time could be considered as "constant", it seems that something is going wrong with this kind of clock.

Any idea?

Thanks

Hector

PS: Ubuntu 2.6.24.-25-rt is based on 2.6.24.7-rt27 patch (link <http://packages.ubuntu.com/hardy-updates/linux-restricted-modules-2.6.24-25-rt>)

void make_job ()
{
long temp = 0;
int index, index2 = 0;

 for (index = 0; index < 5000; index ++) {
    temp += index;
    if (index%97 == 0) {
      for (index2 = 0; index2 < 1000; index2 ++) {
         temp +=index;
      }
    }

}
}

--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html