So I've been using the attached test case (a hacked up version of
sched_jitter, which can now be found in ltp) to measure jitter in a
cpu-bound workload. The idea being if nothing preempts us, we might get
some irq caused jitter, but it should be pretty minimal.
Only recently I had noticed it wasn't that minimal. For 2.5 seconds of
work, I was seeing up to 5-10ms of jitter, which seemed a bit high.
So I dug in and instrumented the kernel and logged any time we got
preempted by a process, or an irq blocked us, or even time spent waiting
on raw locks and seqlocks.
With all the instrumenting I could, I could only account for maybe 2% of
the jitter (in one case the jitter was 1.5ms, and I could only account
for 30us from interrupt overhead).
Finally I rebuilt the test using -O2, and suddenly the jitter dropped
way down, and was then 90% or so accounted for by the instrumentation.
The issue seems to be that building w/ -O1, the compiler is doing
something pretty badly that causes the execution time for a fixed amount
of work to be much more variable.
Anyway, I wanted to hit the list with this so folks could look at it and
let me know if such severe jitter was expected from just compile
options?
thanks
-john
To build:
gcc -lrt -O1 sched_jitter.c -o sched_jitter-O1
gcc -lrt -O2 sched_jitter.c -o sched_jitter-O2
Here's example output:
./sched_jitter-O1
delta: 2479.231934 ms
delta: 2476.494629 ms
delta: 2473.964355 ms
delta: 2474.239746 ms
delta: 2472.457275 ms
delta: 2476.843262 ms
delta: 2475.494141 ms
delta: 2478.266113 ms
delta: 2476.601074 ms
delta: 2475.466553 ms
max jitter: 6.774889 ms
average runtime: 2475.905762 ms
./sched_jitter-O2
delta: 2069.088867 ms
delta: 2069.086914 ms
delta: 2068.875977 ms
delta: 2068.900146 ms
delta: 2068.948242 ms
delta: 2068.889893 ms
delta: 2068.878906 ms
delta: 2068.915283 ms
delta: 2068.913086 ms
delta: 2068.939453 ms
max jitter: 212.876007 us
average runtime: 2068.943848 ms
/* Filename: sched_jitter.c
* Author: John Stultz <johnstul@xxxxxxxxxx>
* Description: This test measures scheduling jitter w/ realtime
* processes. It spawns a realtime thread that repeatedly times how long
* it takes to do a fixed amount of work. It then prints out the maximum
* jitter seen (longest execution time - the shortest execution time).
* It also spawns off a realtime thread of higher priority that simply
* wakes up and goes back to sleep. This tries to measure how much
* overhead the scheduler adds in switching quickly to another task and
* back.
*
* 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, 2007
*
* 2006-May-05: Initial version by John Stultz <johnstul@xxxxxxxxxx>
* 2007-July-18: Support to gather stats by Ankita Garg <ankita@xxxxxxxxxx>
*/
#include <stdio.h>
#include <time.h>
#include <pthread.h>
#include <sched.h>
#include <unistd.h>
#include <sys/mman.h>
#include <sys/prctl.h>
#define PR_PREEMPT_TRACING 23
#define NUMRUNS 10
#define NUMLOOPS 10000000
#define NSEC_PER_SEC 1000000000
#define WORKLEN 64
char array[WORKLEN];
unsigned long long ts_sub(struct timespec a , struct timespec b)
{
unsigned long long first, second;
first = (unsigned long long)a.tv_sec * NSEC_PER_SEC + a.tv_nsec;
second = (unsigned long long)b.tv_sec * NSEC_PER_SEC + b.tv_nsec;
return first - second;
}
void print_unit(unsigned long long val)
{
if (val > 1000000)
printf("%f ms\n", (float)(val)/1000000);
else if (val > 1000)
printf("%f us\n", (float)(val)/1000);
else
printf("%f ns\n", (float)val);
}
void do_work(int runs)
{
int i, j;
for (i=0; i < runs; i++) {
for (j=0; j < WORKLEN-1; j++)
array[j] = array[j]+array[j+1];
for (j=0; j < WORKLEN-1; j++)
array[j] = array[j]-array[j+1];
}
}
int main(int argc, char *argv[])
{
struct sched_param param;
struct timespec start, stop;
int i;
unsigned long long delta;
unsigned long long min=-1, max=0;
unsigned long long avg=0;
param.sched_priority = sched_get_priority_max(SCHED_FIFO);
sched_setscheduler(0, SCHED_FIFO, ¶m);
mlockall(MCL_CURRENT|MCL_FUTURE);
for (i=0; i < NUMRUNS; i++) {
do_work(1); /* warm cache */
/* do test */
// prctl(PR_PREEMPT_TRACING, 1);
clock_gettime(CLOCK_MONOTONIC, &start);
do_work(NUMLOOPS);
clock_gettime(CLOCK_MONOTONIC, &stop);
// prctl(PR_PREEMPT_TRACING, 0);
/* calc delta, min and max */
delta = ts_sub(stop, start);
if (delta < min)
min = delta;
if (delta> max)
max = delta;
avg += delta;
printf("delta: ");
print_unit(delta);
usleep(1); /* let other things happen */
}
printf("max jitter: ");
print_unit(max - min);
printf("average runtime: ");
print_unit(avg/NUMRUNS);
return 0;
}
