Performance issue SCHED_OTHER over SCHED_RR; bug in real time policy?

[Thanh Ly <thanh.ly@logica.com>]

[-- Attachment #1: Type: text/plain, Size: 2976 bytes --]

Dear Linux GURU's,

We've been experimenting with the scheduler for quite a time and there
is one thing which bothers us. For some reason we cannot explain why the
SCHED_FIFO and SCHED_RR is slower than SCHED_OTHER.

For our experiment We've created a simple function which calculates the
fibonacci number sequence using a for loop (1 billion loops). We've
measured the wall time and the cpu usage using getrusage().

We've run this program on a dual-core Intel CPU machine (Intel(R)
Core(TM)2 Duo CPU T7500  @ 2.20GHz) running kernel version
2.6.27-13-generic (Ubuntu 8.10).

First only 1 thread will calculate the fibonacci number and after that 5
threads will each do the same calculations. Each test we've executed 5
times. The measured time has been written to a log file. All threads are
executed with an equal priority (inherited from process).

Summary of log analysis:
Executed with 1 thread

Average time->      Walltime     Ruage time
------------------------------------------------
SCHED_OTHER           4.7s          4.7s
SCHED_FIFO*           4.7s          4.7s        
SCHED_RR*             4.7s          4.7s

* However for 2 measurements of FIFO and 1 of RR
  a value of 13s has been measured!!!

Executed with 5 threads

Average time->      Walltime     Ruage time
------------------------------------------------
SCHED_OTHER           12.5s         5.0s
SCHED_FIFO**          15.1s         5.0s        
SCHED_RR***           15.5s         5.6s

** In run 3 thread 3/4 has a larger time (5.6s);
   Each fifth thread has a time of 4.7s being
   equal to the case of 1 thread execution.
*** Within each run the times are fairly the same
    with an occasional outlier.
    Between the runs the walltime jitters between
    13.7s and 16.3s

Conclusions:
1) There seems to be a bug in the real-time scheduling policies.
2) Despite the similarity between SCHED_OTHER and SCHED_RR
   the performance of SCHED_OTHER is better than SCHED_RR
   even though SCHED_RR is a 'real-time' policy (with always
   a higher priority!).

If our conclusion is correct has this bug already been reported?
Is there an explanation for the better performance of SCHED_OTHER
over SCHED_RR?

With regards,

Thanh Ly


Please help Logica to respect the environment by not printing this email  /  Merci d'aider Logica à préserver l'environnement en évitant d'imprimer ce mail /  Bitte drucken Sie diese Nachricht nicht aus und helfen Sie so Logica dabei die Umwelt zu schuetzen  /  Por favor ajude a Logica a respeitar o ambiente não imprimindo este correio electrónico.



This e-mail and any attachment is for authorised use by the intended recipient(s) only. It may contain proprietary material, confidential information and/or be subject to legal privilege. It should not be copied, disclosed to, retained or used by, any other party. If you are not an intended recipient then please promptly delete this e-mail and any attachment and all copies and inform the sender. Thank you.


[-- Attachment #2: main.c --]
[-- Type: text/x-csrc, Size: 5848 bytes --]

/*
 * main.c
 *
 *  Created on: Feb 24, 2009
 *      Author: Thanh
 */

#define _GNU_SOURCE
#include <stdio.h>
#include <stdlib.h>
#include <pthread.h>
#include <sys/time.h>
#include <sys/resource.h>
#include <unistd.h>
#include <sched.h>
#include <string.h>
#include <time.h>
#include <sys/time.h>		/* gettimeofday() */

//time diff struct
typedef struct {
	int secs;
	int usecs;
} TIME_DIFF;

typedef struct rusage RUsage;

typedef struct fiboargs {
	int n;
	TIME_DIFF *	difference;
} FiboArgs;

typedef struct threads{
	pthread_t thread;
	FiboArgs *args;
	int index;
} MyThreads;

typedef struct arguments
{
	int cpu;
	void *(*function)(void*);
	void *arg;
	int policy;
	int priority;

} Arguments;

MyThreads* ThreadsList[20] = {NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL};

TIME_DIFF * my_difftime (struct timeval * start, struct timeval * end)
{
	TIME_DIFF * diff = (TIME_DIFF *) malloc ( sizeof (TIME_DIFF) );

	if (start->tv_sec == end->tv_sec) {
		diff->secs = 0;
		diff->usecs = end->tv_usec - start->tv_usec;
	}
	else {
		diff->usecs = 1000000 - start->tv_usec;
		diff->secs = end->tv_sec - (start->tv_sec + 1);
		diff->usecs += end->tv_usec;
		if (diff->usecs >= 1000000) {
			diff->usecs -= 1000000;
			diff->secs += 1;
		}
	}

	return diff;
}

void fibonacci(FiboArgs *arg)
{
	int i =0;
	unsigned long result = 1;
	unsigned long n1 = 1 ,n2 = 1;

	RUsage usage_start, usage_end;

	getrusage (1, &usage_start);
	for (i = 2; i < arg->n; i++)
	{
		result = n1 + n2;
		n1 = n2;
		n2 = result;
	}
	getrusage (1, &usage_end);

	struct timeval stopTime;
	stopTime = usage_end.ru_utime;

	struct timeval startTime;
	startTime = usage_start.ru_utime;

	TIME_DIFF *	difference;
	difference = my_difftime (&startTime, &stopTime);

	arg->difference = difference;
	pthread_exit (NULL);
}

void printHelp()
{
	printf("Usage: multithread <policy> <prio> <threads>\n");
	printf("  <policy>	In which mode the process has to run\n");
	printf("  		'fifo'\n");
	printf("		'rr'.\n");
	printf("		'others'.\n");
	printf("  <prio> =	0 .. 99 - the priority for the process\n");
	printf("  <threads> =	1 .. 20 - Amounts of threads to run\n");
}

int getPolicy(char *text)
{
	if (strcmp(text,"fifo") == 0)
	{
		return SCHED_FIFO;
	}
	else if (strcmp(text,"rr") == 0)
	{
		return SCHED_RR;
	}
	else if (strcmp(text,"batch") == 0)
	{
		return SCHED_BATCH;
	}
	else
	{
		return SCHED_OTHER;
	}
}

//this is the wrapper thread which will set its affinity to the given core.
void wrapperThread(Arguments *arg)
{
	pthread_t thisThread;
	cpu_set_t cpuset;

	thisThread = pthread_self();
	CPU_ZERO(&cpuset);
	CPU_SET(arg->cpu,&cpuset);

	pthread_setaffinity_np(thisThread,sizeof(cpu_set_t),&cpuset);
	arg->function(arg->arg);
	free(arg);
}

pthread_t runThread(int core, int policy, int priority,  void *(*function)(void*), void *arg)
{
	int rc;
	pthread_attr_t attr;

	pthread_t thread;
	if (core == -1)
	{
		pthread_create(&thread, NULL, function, arg);
	}
	else
	{
		Arguments *args = malloc(sizeof(Arguments));
		args->cpu = core;
		args->function = function;
		args->arg = arg;
		args->policy = policy;
		args->priority = priority;

		pthread_attr_init(&attr);
		pthread_attr_setinheritsched(&attr, PTHREAD_INHERIT_SCHED);

		rc = pthread_create(&thread, &attr, (void*)wrapperThread, (void*)args);
		if (rc){
			printf("ERROR; return code from pthread_create() is %d\n", rc);
		}
	}

	return thread;
}

/*
 * The program has to be executed with super user privilege.
 * 3 arguments are required
 * policy				: can be "fifo" "rr" "other" "batch"
 * priority				: has to be 0 when policy is other and between 1 and 99 when fifo or other
 * amount of thread		: between 1 and 20
 */
int main( int argc, char** argv )
{
	int times;
	int policy,prior,threadsNr;
	MyThreads *t1;
	TIME_DIFF *	difference;
	struct sched_param param;
	if (argc == 1)
	{
		printHelp();
	}
	else if (argc == 4)
	{
		policy = getPolicy(argv[1]);
		prior = atoi(argv[2]);
		threadsNr = atoi(argv[3]);

		if (prior < 0 || prior > 99)
		{
			printf("Priority is wrong\n");
			exit(1);
		}

		if (threadsNr < 1 || threadsNr > 20)
		{
			printf("The amount of threads can only be from 1 to 20\n");
			exit(1);
		}

		param.__sched_priority = prior;
		if (sched_setscheduler(0,policy,&param) != 0)
		{
			printf("Could not set scheduler priority!\nGiven priority is not correct\n");
			exit(1);
		}

		struct timeval myTVstart, myTVend;
		gettimeofday (&myTVstart, NULL);

		for (times = 0; times < threadsNr; times++)
		{
			//create our argument for our thread.
			t1 = malloc(sizeof(MyThreads));
			t1->args = malloc(sizeof(FiboArgs));
			t1->args->n = 1000000000; //To make sure it takes a considerable time to calculate it.
			t1->args->difference = NULL;
			t1->index = times;
			t1->thread = runThread(-1,policy,prior,(void*)fibonacci,t1->args);
			ThreadsList[times] = t1;
		}

		for (times = 0; times < threadsNr; times++)
		{
			pthread_join ( ThreadsList[times]->thread, NULL );
		}
		gettimeofday (&myTVend, NULL);

		for (times = 0; times < threadsNr; times++)
		{
			printf(" Thread [%d] CPU usage time %3d.%06d secs\n",ThreadsList[times]->index,ThreadsList[times]->args->difference->secs,ThreadsList[times]->args->difference->usecs);
			free(ThreadsList[times]->args->difference);
			free(ThreadsList[times]->args);
			free(ThreadsList[times]);
		}
		difference = my_difftime (&myTVstart, &myTVend);
		printf ("Wall time: %3d.%06d secs.\n", difference->secs, difference->usecs);
		free(difference);
	}
	else
	{
		printf("3 arguments are required!\n");
	}

	return 0;
}

[-- Attachment #3: total.log --]
[-- Type: text/x-log, Size: 5545 bytes --]

###############OTHER POLICY##############
1 THREAD
==== Run 0 ====
 Thread [0] CPU usage time   4.712294 secs
Wall time:   4.710180 secs.
==== Run 1 ====
 Thread [0] CPU usage time   4.672292 secs
Wall time:   4.671690 secs.
==== Run 2 ====
 Thread [0] CPU usage time   4.652290 secs
Wall time:   4.652088 secs.
==== Run 3 ====
 Thread [0] CPU usage time   4.672292 secs
Wall time:   4.675662 secs.
==== Run 4 ====
 Thread [0] CPU usage time   4.684292 secs
Wall time:   4.683043 secs.

5 THREADS
==== Run 0 ====
 Thread [0] CPU usage time   4.948309 secs
 Thread [1] CPU usage time   5.012313 secs
 Thread [2] CPU usage time   5.000312 secs
 Thread [3] CPU usage time   4.980311 secs
 Thread [4] CPU usage time   4.960310 secs
Wall time:  12.548983 secs.
==== Run 1 ====
 Thread [0] CPU usage time   4.968310 secs
 Thread [1] CPU usage time   5.044315 secs
 Thread [2] CPU usage time   4.968310 secs
 Thread [3] CPU usage time   4.964310 secs
 Thread [4] CPU usage time   4.996312 secs
Wall time:  12.556867 secs.
==== Run 2 ====
 Thread [0] CPU usage time   4.948309 secs
 Thread [1] CPU usage time   5.028314 secs
 Thread [2] CPU usage time   4.996312 secs
 Thread [3] CPU usage time   4.972310 secs
 Thread [4] CPU usage time   4.984311 secs
Wall time:  12.493784 secs.
==== Run 3 ====
 Thread [0] CPU usage time   5.000312 secs
 Thread [1] CPU usage time   4.952309 secs
 Thread [2] CPU usage time   4.972310 secs
 Thread [3] CPU usage time   4.964310 secs
 Thread [4] CPU usage time   4.976311 secs
Wall time:  12.459550 secs.
==== Run 4 ====
 Thread [0] CPU usage time   4.992312 secs
 Thread [1] CPU usage time   4.944309 secs
 Thread [2] CPU usage time   4.976311 secs
 Thread [3] CPU usage time   4.976311 secs
 Thread [4] CPU usage time   4.988311 secs
Wall time:  12.465256 secs.

###############FIFO POLICY################
1 THREAD
==== Run 0 ====
 Thread [0] CPU usage time   4.676292 secs
Wall time:   4.677456 secs.
==== Run 1 ====
 Thread [0] CPU usage time  13.864866 secs
Wall time:  13.863353 secs.
==== Run 2 ====
 Thread [0] CPU usage time  13.488843 secs
Wall time:  13.496607 secs.
==== Run 3 ====
 Thread [0] CPU usage time   4.664291 secs
Wall time:   4.663169 secs.
==== Run 4 ====
 Thread [0] CPU usage time   4.664291 secs
Wall time:   4.662964 secs.

5 THREADS
==== Run 0 ====
 Thread [0] CPU usage time   4.960310 secs
 Thread [1] CPU usage time   5.000312 secs
 Thread [2] CPU usage time   5.012313 secs
 Thread [3] CPU usage time   5.072317 secs
 Thread [4] CPU usage time   4.672292 secs
Wall time:  15.125197 secs.
==== Run 1 ====
 Thread [0] CPU usage time   4.988311 secs
 Thread [1] CPU usage time   5.040315 secs
 Thread [2] CPU usage time   4.984311 secs
 Thread [3] CPU usage time   5.060316 secs
 Thread [4] CPU usage time   4.672292 secs
Wall time:  15.079644 secs.
==== Run 2 ====
 Thread [0] CPU usage time   4.960310 secs
 Thread [1] CPU usage time   5.016313 secs
 Thread [2] CPU usage time   4.976311 secs
 Thread [3] CPU usage time   5.092318 secs
 Thread [4] CPU usage time   4.672292 secs
Wall time:  15.044318 secs.
==== Run 3 ====
 Thread [0] CPU usage time   4.956309 secs
 Thread [1] CPU usage time   5.004312 secs
 Thread [2] CPU usage time   5.588349 secs
 Thread [3] CPU usage time   5.676354 secs
 Thread [4] CPU usage time   4.688293 secs
Wall time:  15.711974 secs.
==== Run 4 ====
 Thread [0] CPU usage time   4.972310 secs
 Thread [1] CPU usage time   5.016313 secs
 Thread [2] CPU usage time   4.996312 secs
 Thread [3] CPU usage time   5.048315 secs
 Thread [4] CPU usage time   4.672292 secs
Wall time:  15.123535 secs.

#############ROUND ROBIN POLICY############
1 THREAD
==== Run 0 ====
 Thread [0] CPU usage time   4.664291 secs
Wall time:   4.666622 secs.
==== Run 1 ====
 Thread [0] CPU usage time   4.668291 secs
Wall time:   4.665519 secs.
==== Run 2 ====
 Thread [0] CPU usage time   4.668291 secs
Wall time:   4.666018 secs.
==== Run 3 ====
 Thread [0] CPU usage time  13.644852 secs
Wall time:  13.642246 secs.
==== Run 4 ====
 Thread [0] CPU usage time   4.668291 secs
Wall time:   4.667357 secs.

5 THREADS
==== Run 0 ====
 Thread [0] CPU usage time   5.588349 secs
 Thread [1] CPU usage time   4.996312 secs
 Thread [2] CPU usage time   5.884367 secs
 Thread [3] CPU usage time   6.220388 secs
 Thread [4] CPU usage time   5.924370 secs
Wall time:  15.091071 secs.
==== Run 1 ====
 Thread [0] CPU usage time   5.300331 secs
 Thread [1] CPU usage time   5.316332 secs
 Thread [2] CPU usage time   5.208325 secs
 Thread [3] CPU usage time   5.196324 secs
 Thread [4] CPU usage time   5.168323 secs
Wall time:  13.720632 secs.
==== Run 2 ====
 Thread [0] CPU usage time   5.576348 secs
 Thread [1] CPU usage time   5.748359 secs
 Thread [2] CPU usage time   7.040440 secs
 Thread [3] CPU usage time   5.720357 secs
 Thread [4] CPU usage time   5.456341 secs
Wall time:  16.133396 secs.
==== Run 3 ====
 Thread [0] CPU usage time   5.280330 secs
 Thread [1] CPU usage time   5.252328 secs
 Thread [2] CPU usage time   5.304331 secs
 Thread [3] CPU usage time   6.924432 secs
 Thread [4] CPU usage time   5.220326 secs
Wall time:  15.872640 secs.
==== Run 4 ====
 Thread [0] CPU usage time   5.996374 secs
 Thread [1] CPU usage time   5.916369 secs
 Thread [2] CPU usage time   6.196387 secs
 Thread [3] CPU usage time   6.212388 secs
 Thread [4] CPU usage time   6.800425 secs
Wall time:  16.331687 secs.