Re: -O option causing test jitter?

[Steven Rostedt <rostedt@xxxxxxxxxxx>]

On Thu, 17 Apr 2008, john stultz wrote:
>
> 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?
>

I think this may simply be a simple case of cache misses.

Attached is two files: sched_jitter-test.c and do_work.S. I found that by
switching the positions of do_work1 and do_work2, which ever one is first
performs better. do_work1 is me copying the output of objdump of -O1 of
do_work, and do_work2 is copying the output from objdump of -O2.

For true realtime predictability, x86 architecture truly sucks :-p

-- Steve

/*    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 NUMLOOPS 100
#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 runme(void (*work)(int))
{
	struct timespec start, stop;
	int i;
	unsigned long long delta;
	unsigned long long min=-1, max=0;
	unsigned long long avg=0;

        for (i=0; i < NUMRUNS; i++) {

		work(1); /* warm cache */

		/* do test */
//		prctl(PR_PREEMPT_TRACING, 1);
		clock_gettime(CLOCK_MONOTONIC, &start);
		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);
}

extern void do_work1(int);
extern void do_work2(int);

int main(int argc, char *argv[])
{
	struct sched_param param;

	param.sched_priority = sched_get_priority_max(SCHED_FIFO);
	sched_setscheduler(0, SCHED_FIFO, &param);
	mlockall(MCL_CURRENT|MCL_FUTURE);

	runme(do_work1);
	runme(do_work2);
	return 0;
}

.align 128
.globl do_work1
do_work1:
	mov    $0x0,%ecx
	test   %edi,%edi
	jg     1f
	retq 
2:	movzbl array+1(%rdx),%eax
	add    %al,array(%rdx)
	add    $0x1,%rdx
	cmp    $0x3f,%rdx
	jne    2b
	mov    $0x0,%dl
3:	movzbl array(%rdx),%eax
	sub    array+1(%rdx),%al
	mov    %al,array(%rdx)
	add    $0x1,%rdx
	cmp    $0x3f,%rdx
	jne    3b
	add    $0x1,%ecx
	cmp    %edi,%ecx
	je     4f
1:	mov    $0x0,%edx
	jmp    2b
4:	retq 



.align 128
.globl do_work2
do_work2:
	xor    %ecx,%ecx
	test   %edi,%edi
	jle    1f
4:	xor    %edx,%edx
2:	movzbl array+1(%rdx),%eax
	add    %al,array(%rdx)
	add    $0x1,%rdx
	cmp    $0x3f,%rdx
	jne    2b
	xor    %dl,%dl
3:	movzbl array(%rdx),%eax
	sub    array+1(%rdx),%al
	mov    %al,array(%rdx)
	add    $0x1,%rdx
	cmp    $0x3f,%rdx
	jne    3b
	add    $0x1,%ecx
	cmp    %edi,%ecx
	jne    4b
1:	retq