On Thu, 2006-05-18 at 10:47 +0200, Ingo Molnar wrote:
> * Sébastien Dugué <[email protected]> wrote:
>
> > Darren,
> >
> > On Mon, 2006-05-15 at 18:30 -0700, Darren Hart wrote:
> > > Following Ingo's example I have included the modified test case (please see
> > > the original mail for librt.h) that starts the trace before each sleep and
> > > disables it after we wake up. If we have missed a period, we print the
> > > trace.
> > >
> >
> > Your test program fails (at least on my box) as the overhead of
> > starting and stopping the trace in the 5 ms period is just too high.
> >
> > By moving the latency_trace_start() at the start of the thread
> > function and latency_trace_stop() at the end, everything runs fine. I
> > did not have any period missed even under heavy load.
>
> could you send us the fixed testcase?
No problem, see attachment.
>
> thanks for tracking this down. FYI, the latency of stopping the trace is
> that expensive because we are copying large amounts of trace data
> around, to ensure that /proc/latency_trace is always consistent and is
> updated atomically, and to make sure that we can update the trace from
> interrupt contexts too - without /proc/latency_trace accesses blocking
> them. The latency of stopping the trace is hidden from the tracer itself
> - but it cannot prevent indirect effects such as your app from missing
> periods, if the periods are in the 5msec range.
>
Thanks for the explanation, will have to look deeper into the code
to understand how it works though.
Sébastien.
/* Filename: sched_latency_lkml.c
* Author: Darren Hart <[email protected]>
* Description: Measure the latency involved with periodic scheduling.
* Compilation: gcc -O2 -g -D_GNU_SOURCE -I/usr/include/nptl -I -L/usr/lib/nptl -lpthread -lrt -lm sched_latency_lkml.c -o sched_latency_lkml
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation; either version 2 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program; if not, write to the Free Software
* Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA.
*
* Copyright (C) IBM Corporation, 2006
*
* 2006-May-10: Initial version by Darren Hart <[email protected]>
*/
#include <stdio.h>
#include <stdlib.h>
#include <math.h>
#include "librt.h"
#define PRIO 98
//#define PERIOD 17*NS_PER_MS
//#define ITERATIONS 100
#define ITERATIONS 10000
#define PERIOD 5*NS_PER_MS
#define PASS_US 100
#define LATENCY_TRACE 1
#ifdef LATENCY_TRACE
#define latency_trace_enable() \
system("echo 0 > /proc/sys/kernel/trace_all_cpus"); \
system("echo 1 > /proc/sys/kernel/trace_enabled"); \
system("echo 0 > /proc/sys/kernel/trace_freerunning"); \
system("echo 0 > /proc/sys/kernel/trace_print_at_crash"); \
system("echo 1 > /proc/sys/kernel/trace_user_triggered"); \
system("echo 0 > /proc/sys/kernel/trace_verbose"); \
system("echo 0 > /proc/sys/kernel/preempt_max_latency"); \
system("echo 0 > /proc/sys/kernel/preempt_thresh"); \
system("[ -e /proc/sys/kernel/wakeup_timing ] && echo 1 > /proc/sys/kernel/wakeup_timing"); \
system("echo 1 > /proc/sys/kernel/mcount_enabled");
#define latency_trace_start() gettimeofday(0,1)
#define latency_trace_stop() gettimeofday(0,0)
#define latency_trace_print() system("cat /proc/latency_trace");
#else
#define latency_trace_enable() do { } while (0)
#define latency_trace_start() do { } while (0)
#define latency_trace_stop() do { } while (0)
#define latency_trace_print() do { } while (0)
#endif
nsec_t start;
int retval;
void *periodic_thread(void *arg)
{
struct thread *t = (struct thread *)arg;
int i;
int delay, avg_delay = 0, start_delay, min_delay = 0x7FFFFFF, max_delay = 0;
int failures = 0;
nsec_t next=0, now=0, sched_delta=0, delta=0, prev=0;
retval = 0;
latency_trace_start();
prev = start;
next = start;
now = rt_gettime();
start_delay = (now - start)/NS_PER_US;
//printf("ITERATION DELAY(US) MAX_DELAY(US) FAILURES\n");
//printf("--------- --------- ------------- --------\n");
for (i = 1; i <= ITERATIONS; i++) {
/* wait for the period to start */
next += PERIOD;
prev = now;
now = rt_gettime();
if (next < now) {
printf("\n\nPERIOD MISSED!\n");
printf(" scheduled delta: %8llu us\n", sched_delta/1000);
printf(" actual delta: %8llu us\n", delta/1000);
printf(" latency: %8llu us\n", (delta-sched_delta)/1000);
printf("---------------------------------------\n");
printf(" previous start: %8llu us\n", (prev-start)/1000);
printf(" now: %8llu us\n", (now-start)/1000);
printf(" scheduled start: %8llu us\n", (next-start)/1000);
printf("next scheduled start is in the past!\n");
retval = 1;
latency_trace_print();
break;
}
sched_delta = next - now; /* how long we should sleep */
delta = 0;
do {
rt_nanosleep(next - now);
delta += rt_gettime() - now; /* how long we did sleep */
now = rt_gettime();
} while (now < next);
/* start of period */
now = rt_gettime();
delay = (now - start - (nsec_t)i*PERIOD)/NS_PER_US;
if (delay < min_delay)
min_delay = delay;
if (delay > max_delay)
max_delay = delay;
if (delay > PASS_US)
failures++;
avg_delay += delay;
/* continuous status ticker */
//printf("%9i %9i %13i %8i\r", i, delay, max_delay, failures);
//fflush(stdout);
busy_work_ms(1);
}
latency_trace_stop();
avg_delay /= ITERATIONS;
printf("\n\n");
printf("Start Latency: %4d us: %s\n", start_delay,
start_delay < PASS_US ? "PASS" : "FAIL");
printf("Min Latency: %4d us: %s\n", min_delay,
min_delay < PASS_US ? "PASS" : "FAIL");
printf("Avg Latency: %4d us: %s\n", avg_delay,
avg_delay < PASS_US ? "PASS" : "FAIL");
printf("Max Latency: %4d us: %s\n", max_delay,
max_delay < PASS_US ? "PASS" : "FAIL");
printf("Failed Iterations: %d\n\n", failures);
return NULL;
}
int main(int argc, char *argv[])
{
int per_id, mas_id;
printf("-------------------------------\n");
printf("Scheduling Latency\n");
printf("-------------------------------\n\n");
printf("Running %d iterations with a period of %d ms\n", ITERATIONS, PERIOD/NS_PER_MS);
printf("Expected running time: %d s\n\n", (nsec_t)ITERATIONS*PERIOD/NS_PER_SEC);
latency_trace_enable();
start = rt_gettime();
per_id = create_fifo_thread(periodic_thread, (void*)0, PRIO);
join_thread(per_id);
join_threads();
return retval;
}
[Index of Archives]
[Kernel Newbies]
[Netfilter]
[Bugtraq]
[Photo]
[Stuff]
[Gimp]
[Yosemite News]
[MIPS Linux]
[ARM Linux]
[Linux Security]
[Linux RAID]
[Video 4 Linux]
[Linux for the blind]
[Linux Resources]
