Weird timing results in C


 
Thread Tools Search this Thread
Top Forums Programming Weird timing results in C
# 1  
Old 09-07-2009
Weird timing results in C

I was running some timings in my code to see which of several functions was the best and I've been getting some odd results. Here's the code I'm using:
Code:
static double time_loop(int (*foo)(int)) {
	clock_t start, end;
	int n = 0, i = 0;
	start = clock();
	for (; i <= MAXN; i++)
		if ((*foo)(i)) n++;
	end = clock();
	if (n != 50847534)
		return -1;	// Error
	return ((double) (end - start)) / CLOCKS_PER_SEC;
}

static double median3(int (*foo)(int)) {
	double t1 = time_loop(foo);
	double t2 = time_loop(foo);
	double t3 = time_loop(foo);
	printf("  ((%f %f %f))\n", t1, t2, t3);
	int errors = 0;
	if (t1 < 0)
		errors++;
	if (t2 < 0)
		errors++;
	if (t3 < 0)
		errors++;
	if (errors > 0)
		return -errors;
	if (t1 > t2) {
		if (t2 > t3)
			return t2;
		return t3 < t1 ? t3 : t1;
	} else {
		if (t1 > t3)
			return t1;
		return t3 < t2 ? t3 : t2;
	}
}

The functions that I'm passing to time_loop are pure functions -- they're not making any changes to global variables. And yet every time I run this, my debugging line in median3 shows that the third invocation takes significantly longer than the others. Sample run:
Code:
  ((4.560000 3.750000 6.540000))
Original: 4.560000 s
  ((4.920000 3.760000 6.690000))
Original: 4.920000 s
  ((4.190000 3.750000 6.620000))
Original: 4.190000 s
  ((3.820000 3.130000 5.640000))
New:      3.820000 s
  ((3.580000 3.150000 5.580000))
New:      3.580000 s
	  ((3.670000 3.140000 5.510000))
New:      3.670000 s

Why is that? These functions are entirely deterministic, and nothing is changing between invocations. But I see a strong pattern of time - smaller time - much longer time.

As for cache effects, the functions rely on a 125 MB global array, so that's not going to fit even in my 6MB L3. (Even if it did you'd expect the second and third invocations to be fast.)
# 2  
Old 09-08-2009
Can you post the code for function foo.
# 3  
Old 09-09-2009
Code:
for (; i <= MAXN; i++)
		if ((*foo)(i)) n++;

That iterates MAXN which must be at least 50847534 - for each of the three calls to time_loop() the function ptr is jumping to the same function. Unless that code has to dynamically allocate memory or there is OS contention for some resource, there ought not be those differences.

I happen not to like the static declaration of functions for a variety of reasons except in certain instances-- But that is very probably not the cause of this problem.

You need to call getrusage() before and after - like you now do with clock() to see what is happening in the world of system resources.

Also clock() is just wall time, use the times() function to get system & user time - as consumed by parent & child.

I think shamrock wants to see that you are not calling exec or something else that eats the system resources or causes high kernel times maybe.
# 4  
Old 09-09-2009
More questions. What type of system are you using? What OS?
# 5  
Old 09-09-2009
It would be nice to see what foo is doing and you can use gprof for profiling your code to figure out why some calls are taking longer.
# 6  
Old 09-10-2009
Nothing funny, just bit manipulation and accessing a big array. The functions are all similar and all display the same results; here's one example:
Code:
#define GET(b) ((sieve[(b)>>5]>>((b)&31))&1)
static int isprime3(int p) { return (p&1) ? p > 2 && !GET(p >> 1) : p == 2; }

The system is 32-bit Xubuntu 8.10 on a quad-core Phenom II.

As I said before, the results are consistent. When I call
Code:
	printf("New:     %f s\n", median3(&isprime3));
	printf("New:     %f s\n", median3(&isprime3));
	printf("New:     %f s\n", median3(&isprime3));

the time for the first, fourth, and seventh times are fast, the times for the third, sixth, and ninth times are slow, etc.

---------- Post updated at 01:23 AM ---------- Previous update was at 01:18 AM ----------

Quote:
Originally Posted by jim mcnamara
I happen not to like the static declaration of functions for a variety of reasons except in certain instances-- But that is very probably not the cause of this problem.
I don't do it much. If you have advice on better ways to do it, feel free to expound (or give a link!).
# 7  
Old 09-12-2009
With regard to static functions:
I assume this is because the C99 standard says little about implemention of static text other than scope changes -

In large single file programs with a lot of static functions mixed in with auto functions -
I've encounteered really obscure problems in gcc 3.1, cc on HP UX 11.1. For example an auto function not being executed at all. Sounds odd, but it is true. The same "inherited program design" also screwed up optimizations by forcing the complier to make decisions it was not expected to make - according the HP compiler team anyway.

Basically to resolve the problems I had to completely turn off optimzation, and declare all functions static to get correct results. Since a fixed makefile was a requirement for the entire app suite, this meant a big rewrite for several very large programs.

Your problem is nothing like that. It almost HAS to be cache-related Based on what you said about your hardware, if you were to chunk your 125MB of data into 21 ~6MB chunks, then iterate (1,2,3) over each subset chunk the problem would not be there. If it is cache related - and with no other observations to work on that would be my guess.
Login or Register to Ask a Question

Previous Thread | Next Thread

10 More Discussions You Might Find Interesting

1. UNIX for Beginners Questions & Answers

Weird 'find' results

Hello and thanks in advance for any help anyone can offer me I'm trying to learn the find command and thought I was understanding it... Apparently I was wrong. I was doing compound searches and I started getting weird results with the -size test. I was trying to do a search on a 1G file owned by... (14 Replies)
Discussion started by: bodisha
14 Replies

2. Red Hat

Hardware and system timing are different

-> We have 2 servers server1 and server2 server. ->server1 is master application and server2 is slave application server. ->output of server1 hardware and slave timing: # hwclock --show Thu 05 Jun 2014 05:34:08 PM SGT -0.465666 seconds # date Thu Jun 5 17:34:16 SGT 2014 # cd... (6 Replies)
Discussion started by: manjusharma128
6 Replies

3. Shell Programming and Scripting

Timing the shell script

I have two shell scripts, one written with xargs for parallel processing (p1) and the other written in old school way (p3) . when I execute them, i get the below values. $ time ./p1 real 0m25.36s user 0m0.32s sys 0m0.80s $ time ./p3 real 0m23.25s user 0m6.20s sys ... (4 Replies)
Discussion started by: luhah
4 Replies

4. Shell Programming and Scripting

Timing a script

i have a very big script i have that i'd like to add a timeout to. this script runs on a several remote host. i update this script with timeout clause and then copy it over to all the hosts on which it is currently on. basically, i want the timeout to make the script abort/exit if it's... (1 Reply)
Discussion started by: SkySmart
1 Replies

5. Shell Programming and Scripting

Can ctag and cscope support recording search results and displaying the history results ?

Hello , When using vim, can ctag and cscope support recording search results and displaying the history results ? Once I jump to one tag, I can use :tnext to jump to next tag, but how can I display the preview search result? (0 Replies)
Discussion started by: 915086731
0 Replies

6. UNIX for Advanced & Expert Users

byte swapping 32-bit float and weird od results

I'm attempting to read a file that is composed of complex 32-bit floating point values on Solaris 10 that came from a 64-bit Red Hat computer. When I first tried reading the file, it looked like there was a byte-swapping problem and after running the od command on the file Solaris and Red Hat... (2 Replies)
Discussion started by: GoDonkeys
2 Replies

7. Programming

Help with __builtin_prefetch function and it's timing

Hello there, I just needed to know how to get the timing right when using the gcc __builtin_prefetch() function, that is, how many instructions before the actual utilization of the data should I make the prefetch call. I will be measuring the L1 cache hit rate with valgrind's cachegrind,... (3 Replies)
Discussion started by: Tavo
3 Replies

8. Programming

timing your functions

hi everyone. If you have a function created in your code and you want to find out how long it takes for it to run you can use a struct called gettimeofday(). so lets say we have a function like this int myfunction (int r) { /*some math calculations*/ return answer; } How do i set up... (3 Replies)
Discussion started by: bebop1111116
3 Replies

9. Shell Programming and Scripting

Timing out a SSH

I need to make it so an autmated process which involves ssh, times out if ssh prompts for a password. Most of the time it shouldnt prompt for a password. But if it does i need it to time it out or get a status and stop the ssh and log that the ssh failed and move onto the next server. Is there any... (9 Replies)
Discussion started by: rcunn87
9 Replies

10. UNIX for Advanced & Expert Users

scp timing out

having problems using scp in that during peak hours it appears to time out. anyone have similar experiences? any thoughts regarding a solution... (1 Reply)
Discussion started by: jph
1 Replies
Login or Register to Ask a Question