* Posix Execution time clock
@ 2009-12-01 12:14 Hector Perez Tijero
2009-12-01 9:53 ` Uwe Kleine-König
2009-12-01 12:32 ` Luis Claudio R. Goncalves
0 siblings, 2 replies; 6+ messages in thread
From: Hector Perez Tijero @ 2009-12-01 12:14 UTC (permalink / raw)
To: linux-rt-users
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, ¶m_rt) );
CHK ( sched_setscheduler (0, SCHED_FIFO, ¶m_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;
}
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: Posix Execution time clock
2009-12-01 12:14 Posix Execution time clock Hector Perez Tijero
@ 2009-12-01 9:53 ` Uwe Kleine-König
2009-12-01 12:32 ` Luis Claudio R. Goncalves
1 sibling, 0 replies; 6+ messages in thread
From: Uwe Kleine-König @ 2009-12-01 9:53 UTC (permalink / raw)
To: Hector Perez Tijero; +Cc: linux-rt-users
Hi Hector,
On Tue, Dec 01, 2009 at 07:14:45AM -0500, Hector Perez Tijero wrote:
> 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.
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 majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Posix Execution time clock
2009-12-01 12:14 Posix Execution time clock Hector Perez Tijero
2009-12-01 9:53 ` Uwe Kleine-König
@ 2009-12-01 12:32 ` Luis Claudio R. Goncalves
2009-12-02 9:01 ` Hector Perez Tijero
2009-12-02 19:08 ` Uwe Kleine-König
1 sibling, 2 replies; 6+ messages in thread
From: Luis Claudio R. Goncalves @ 2009-12-01 12:32 UTC (permalink / raw)
To: Hector Perez Tijero; +Cc: linux-rt-users
On Tue, Dec 01, 2009 at 07:14:45AM -0500, Hector Perez Tijero wrote:
> 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...
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...
> My previous guess was that such behavior could be caused by the CPU
> frequency scaling but the same happened when I disabled it.
How many CPUs?
>From http://www.tin.org/bin/man.cgi?section=3&topic=clock_gettime :
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 ]
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: Posix Execution time clock
2009-12-01 12:32 ` Luis Claudio R. Goncalves
@ 2009-12-02 9:01 ` Hector Perez Tijero
2009-12-02 19:08 ` Uwe Kleine-König
1 sibling, 0 replies; 6+ messages in thread
From: Hector Perez Tijero @ 2009-12-02 9:01 UTC (permalink / raw)
To: linux-rt-users
Hi again,
Thanks for your really quick replies and your contributions! I have
found some interesting info:
Luis Claudio R. Goncalves escribió:
> On Tue, Dec 01, 2009 at 07:14:45AM -0500, Hector Perez Tijero wrote:
>
>> 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...
>>
>
> 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...
>
>
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...
>
>> My previous guess was that such behavior could be caused by the CPU
>> frequency scaling but the same happened when I disabled it.
>>
>
> How many CPUs?
>
A DualCore.
> >From http://www.tin.org/bin/man.cgi?section=3&topic=clock_gettime :
>
> 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.
>
Yeah, I have check the available clocks in
/sys/devices/system/clocksource/clocksource0/available_clocksource
>>hpet acpi_pm jiffies tsc
and the clock used according to cat
/sys/devices/system/clocksource/clocksource0/current_clocksource
>>hpet
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
> By definition, CLOCK_MONOTONIC seems to be what you want.
>
>
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.
> 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.
>
>
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 majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: Posix Execution time clock
2009-12-01 12:32 ` Luis Claudio R. Goncalves
2009-12-02 9:01 ` Hector Perez Tijero
@ 2009-12-02 19:08 ` Uwe Kleine-König
2009-12-05 2:23 ` Hector Perez Tijero
1 sibling, 1 reply; 6+ messages in thread
From: Uwe Kleine-König @ 2009-12-02 19:08 UTC (permalink / raw)
To: Luis Claudio R. Goncalves; +Cc: Hector Perez Tijero, linux-rt-users
On Tue, Dec 01, 2009 at 10:32:28AM -0200, Luis Claudio R. Goncalves wrote:
> 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.
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 majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: Posix Execution time clock
2009-12-02 19:08 ` Uwe Kleine-König
@ 2009-12-05 2:23 ` Hector Perez Tijero
0 siblings, 0 replies; 6+ messages in thread
From: Hector Perez Tijero @ 2009-12-05 2:23 UTC (permalink / raw)
To: linux-rt-users
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;
}
}
}
}
Uwe Kleine-König escribió:
> On Tue, Dec 01, 2009 at 10:32:28AM -0200, Luis Claudio R. Goncalves wrote:
>
>> 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.
>>
> 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
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2009-12-05 2:23 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2009-12-01 12:14 Posix Execution time clock Hector Perez Tijero
2009-12-01 9:53 ` Uwe Kleine-König
2009-12-01 12:32 ` Luis Claudio R. Goncalves
2009-12-02 9:01 ` Hector Perez Tijero
2009-12-02 19:08 ` Uwe Kleine-König
2009-12-05 2:23 ` Hector Perez Tijero
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).