Benchmark Code

Spire_Jeff
Spire_Jeff Formerly Caffeinated Programmer
in Tips and Tricks
A question was raised in the optimization code thread about how I was benchmarking the code. Because of that, I am posting the code I will be using from now on for testing chunks of code. I welcome any suggestions on how to improve the code and I also welcome anyone out there to test bits of code and post the results.
PROGRAM_NAME='timelineBenchmark'
DEFINE_DEVICE

dvTP	= 10001:1:0


DEFINE_CONSTANT
//Benchmark Constants
integer MAX_NUM_TESTS = 20;


//Place test constants below
DEFINE_TYPE


DEFINE_VARIABLE
//Benchmark Variables DO NOT CHANGE
char sTestDescription[MAX_NUM_TESTS][30]
VOLATILE LONG 	lTL_Times[5] = {10000,10000,10000,10000,10000}
LONG	lTestTime[MAX_NUM_TESTS][6] //1-5 = last values, 6 = running avg of all
LONG  lTestAverageCount[MAX_NUM_TESTS] = 0
VOLATILE INTEGER nTestIndex[MAX_NUM_TESTS]
VOLATILE INTEGER nWORK_IN_PROGRESS[MAX_NUM_TESTS]

//**********************
//Benchmark functions. 
//Call the TestStart function immediately before code to be tested.
//Call the TestFinish function immediately after code to be tested.
//**********************

define_function TestName(integer nMethod, char sName[30]){
	sTestDescription[nMethod] = sName;
}
define_function TestReset(integer nMethod){//Clears averages and sets pointers to first spot.
	stack_var integer x;
	
	nTestIndex[nMethod] = 1;
	nWORK_IN_PROGRESS[nMethod] = 0;
	timeline_kill(nMethod);
	lTestAverageCount[nMethod] = 0;
	for(x=6;x;x--){
		lTestTime[nMethod][x] = 0;
	}
	send_string 0,"'*********************************************************'";
	send_string 0,"'* TEST ',itoa(nMethod),' RESET: ',sTestDescription[nMethod]";
	send_string 0,"'*********************************************************'";
}
define_function TestStart(integer nMethod){
	IF((nTestIndex[nMethod] > 5) or (nTestIndex[nMethod] < 1))
		nTestIndex[nMethod] = 1;

	send_string 0,"'*********************************************************'";
	send_string 0,"'* TEST ',itoa(nMethod),' STARTING: ',sTestDescription[nMethod]";
	send_string 0,"'*********************************************************'";

	nWork_In_Progress[nMethod] = 1;
	TIMELINE_CREATE(type_cast(nMethod),lTL_Times,5,TIMELINE_RELATIVE,TIMELINE_REPEAT);

}
define_function TestFinish(integer nMethod){
	TIMELINE_PAUSE(nMethod);
	lTestTime[nMethod][nTestIndex[nMethod]] = TIMELINE_GET(nMethod);
	TIMELINE_KILL(nMethod);
	lTestTime[nMethod][6] = ((lTestTime[nMethod][6]*lTestAverageCount[nMethod]) + lTestTime[nMethod][nTestIndex[nMethod]])/(lTestAverageCount[nMethod] + 1);
	lTestAverageCount[nMethod]++;

	send_string 0,"'*********************************************************'";
	send_string 0,"'* TEST ',itoa(nMethod),' FINISHED: ',sTestDescription[nMethod]";
	send_string 0,"'* Last run time: ',itoa(lTestTime[nMethod][nTestIndex[nMethod]]),'ms - ',sTestDescription[nMethod]";
	send_string 0,"'* Average run time: ',itoa(lTestTime[nMethod][6]),'ms - over ',itoa(lTestAverageCount[nMethod]),' tests - ',sTestDescription[nMethod]";
	send_string 0,"'*********************************************************'";
	
	IF((nTestIndex[nMethod] >= 5) or (nTestIndex[nMethod] < 1))
		nTestIndex[nMethod] = 1;
	ELSE
		nTestIndex[nMethod]++;
	nWORK_IN_PROGRESS[nMethod] = 0;

}
define_function TestPrintReport(integer nMethod){
	stack_var integer x;
	
	if(nMethod){
		send_string 0,"'*********************************************************'";
		send_string 0,"'* TEST ',itoa(nMethod),' REPORT: ',sTestDescription[nMethod]";
		send_string 0,"'* Most recent 5 runs:'";
		send_string 0,"'* 1: ',itoa(lTestTime[nMethod][1]),'ms'";
		send_string 0,"'* 2: ',itoa(lTestTime[nMethod][2]),'ms'";
		send_string 0,"'* 3: ',itoa(lTestTime[nMethod][3]),'ms'";
		send_string 0,"'* 4: ',itoa(lTestTime[nMethod][4]),'ms'";
		send_string 0,"'* 5: ',itoa(lTestTime[nMethod][5]),'ms'";
		send_string 0,"'*----------------------------------------------------------'";
		send_string 0,"'* Average run time: ',itoa(lTestTime[nMethod][6]),'ms - over ',itoa(lTestAverageCount[nMethod]),' tests'";
		send_string 0,"'*********************************************************'";
	}
	else{
		for(x=1;x<=MAX_NUM_TESTS;x++){ 
			if(lTestTime[x][1]){
				send_string 0,"'*********************************************************'";
				send_string 0,"'* TEST ',itoa(x),' REPORT: ',sTestDescription[x]";
				send_string 0,"'* Most recent 5 runs:'";
				send_string 0,"'* 1: ',itoa(lTestTime[x][1]),'ms'";
				send_string 0,"'* 2: ',itoa(lTestTime[x][2]),'ms'";
				send_string 0,"'* 3: ',itoa(lTestTime[x][3]),'ms'";
				send_string 0,"'* 4: ',itoa(lTestTime[x][4]),'ms'";
				send_string 0,"'* 5: ',itoa(lTestTime[x][5]),'ms'";
				send_string 0,"'*----------------------------------------------------------'";
				send_string 0,"'* Average run time: ',itoa(lTestTime[x][6]),'ms - over ',itoa(lTestAverageCount[x]),' tests'";
				send_string 0,"'*********************************************************'";
			}
		}
	}
}
DEFINE_FUNCTION PutYourFunctionsBelow(){//example function for testing
TestName(20,'Sample Test');//20 is the test ID. Change this accordingly. start at 1. MAX_NUM_TESTS is the highest ID allowed.
TestStart(20);
//Test code goes here!
TestFinish(20);

}

DEFINE_START


DEFINE_EVENT
BUTTON_EVENT[dvTP,1] {  //Run Test

   PUSH: {
   }
}
BUTTON_EVENT[dvTP,2] { //Run Test
   PUSH: {
   }
}
BUTTON_EVENT[dvTP,3] { //Run Test
   PUSH: {
   }
}

BUTTON_EVENT[dvTP,100] 
BUTTON_EVENT[dvTP,101] 
BUTTON_EVENT[dvTP,102] 
BUTTON_EVENT[dvTP,103] 
BUTTON_EVENT[dvTP,104] 
BUTTON_EVENT[dvTP,105] 
BUTTON_EVENT[dvTP,106] 
BUTTON_EVENT[dvTP,107] 
BUTTON_EVENT[dvTP,108] 
BUTTON_EVENT[dvTP,109] 
BUTTON_EVENT[dvTP,110] 
BUTTON_EVENT[dvTP,111] 
BUTTON_EVENT[dvTP,112] 
BUTTON_EVENT[dvTP,113] 
BUTTON_EVENT[dvTP,114] 
BUTTON_EVENT[dvTP,115] 
BUTTON_EVENT[dvTP,116] 
BUTTON_EVENT[dvTP,117] 
BUTTON_EVENT[dvTP,118] 
BUTTON_EVENT[dvTP,119] 
BUTTON_EVENT[dvTP,120]{  //Print reports. channel 100 prints all valid reports.
						//channel 101-120 print a report only for a single test (channel-100)
                 
   PUSH: {
		TestPrintReport(button.input.channel - 100);
   }
}
button_event[dvTp,255]{ //Reset Test Data
	push:{
		stack_var integer x;
		for(x=MAX_NUM_TESTS;x;x--){
			TestReset(x);
		}
	}            
}

Also, let me know if something is not clear.

Ohh, in case it isn't as clear as I think it is, I am running the tests using the diagnostics window and emulate device 10001. After you have run the tests a few times, you can emulate a push on channel 100 to print your reports to the diagnostics window.


Jeff

P.S.
I am going to rerun the For Loop tests with this code and post the results momentarily.
· Share on FacebookShare on Twitter

Comments

  • Spire_Jeff
    Spire_Jeff Formerly Caffeinated Programmer
    Results from the for loop tests using the new benchmark code:
    Line      1 (17:53:52):: *********************************************************
Line      2 (17:53:52):: * TEST 1 REPORT: FOR (nLoop = 1; nLoop <= LENGTH_ARRAY(nInfo); nLoo
Line      3 (17:53:52):: * Most recent 5 runs:
Line      4 (17:53:52):: * 1: 3755ms
Line      5 (17:53:52):: * 2: 3759ms
Line      6 (17:53:52):: * 3: 3754ms
Line      7 (17:53:52):: * 4: 3753ms
Line      8 (17:53:52):: * 5: 3753ms
Line      9 (17:53:52):: *----------------------------------------------------------
Line     10 (17:53:52):: * Average run time: 3754ms - over 5 tests
Line     11 (17:53:52):: *********************************************************
Line     12 (17:53:52):: *********************************************************
Line     13 (17:53:52):: * TEST 2 REPORT: FOR (snLoop = 1; snLoop <= LENGTH_ARRAY(nInfo); sn
Line     14 (17:53:52):: * Most recent 5 runs:
Line     15 (17:53:52):: * 1: 3340ms
Line     16 (17:53:52):: * 2: 3343ms
Line     17 (17:53:52):: * 3: 3344ms
Line     18 (17:53:52):: * 4: 3343ms
Line     19 (17:53:52):: * 5: 3345ms
Line     20 (17:53:52):: *----------------------------------------------------------
Line     21 (17:53:52):: * Average run time: 3342ms - over 5 tests
Line     22 (17:53:52):: *********************************************************
Line     23 (17:53:52):: *********************************************************
Line     24 (17:53:52):: * TEST 3 REPORT: FOR (nLoop = 1; nLoop <= MAX_LENGTH_ARRAY(nInfo); 
Line     25 (17:53:52):: * Most recent 5 runs:
Line     26 (17:53:52):: * 1: 3573ms
Line     27 (17:53:52):: * 2: 3573ms
Line     28 (17:53:52):: * 3: 3571ms
Line     29 (17:53:52):: * 4: 3575ms
Line     30 (17:53:52):: * 5: 3574ms
Line     31 (17:53:52):: *----------------------------------------------------------
Line     32 (17:53:52):: * Average run time: 3572ms - over 5 tests
Line     33 (17:53:52):: *********************************************************
Line     34 (17:53:52):: *********************************************************
Line     35 (17:53:52):: * TEST 4 REPORT: FOR (nLoop = 1, nMax = MAX_LENGTH_ARRAY(nInfo); nL
Line     36 (17:53:52):: * Most recent 5 runs:
Line     37 (17:53:52):: * 1: 1959ms
Line     38 (17:53:52):: * 2: 1959ms
Line     39 (17:53:52):: * 3: 1958ms
Line     40 (17:53:52):: * 4: 1959ms
Line     41 (17:53:52):: * 5: 1959ms
Line     42 (17:53:52):: *----------------------------------------------------------
Line     43 (17:53:52):: * Average run time: 1958ms - over 5 tests
Line     44 (17:53:52):: *********************************************************
Line     45 (17:53:52):: *********************************************************
Line     46 (17:53:52):: * TEST 5 REPORT: FOR (nLoop = MAX_LENGTH_ARRAY(nInfo); nLoop > 0; n
Line     47 (17:53:52):: * Most recent 5 runs:
Line     48 (17:53:52):: * 1: 1793ms
Line     49 (17:53:52):: * 2: 1792ms
Line     50 (17:53:52):: * 3: 1793ms
Line     51 (17:53:52):: * 4: 1793ms
Line     52 (17:53:52):: * 5: 1792ms
Line     53 (17:53:52):: *----------------------------------------------------------
Line     54 (17:53:52):: * Average run time: 1792ms - over 5 tests
Line     55 (17:53:52):: *********************************************************
Line     56 (17:53:52):: *********************************************************
Line     57 (17:53:52):: * TEST 6 REPORT: FOR (nLoop = MAX_LENGTH_ARRAY(nInfo); nLoop; nLoop
Line     58 (17:53:52):: * Most recent 5 runs:
Line     59 (17:53:52):: * 1: 1498ms
Line     60 (17:53:52):: * 2: 1498ms
Line     61 (17:53:52):: * 3: 1498ms
Line     62 (17:53:52):: * 4: 1498ms
Line     63 (17:53:52):: * 5: 1497ms
Line     64 (17:53:52):: *----------------------------------------------------------
Line     65 (17:53:52):: * Average run time: 1497ms - over 5 tests
Line     66 (17:53:52):: *********************************************************
Line     67 (17:53:52):: *********************************************************
Line     68 (17:53:52):: * TEST 7 REPORT: FOR (snLoop = MAX_LENGTH_ARRAY(nInfo); snLoop; snL
Line     69 (17:53:52):: * Most recent 5 runs:
Line     70 (17:53:52):: * 1: 1145ms
Line     71 (17:53:52):: * 2: 1146ms
Line     72 (17:53:52):: * 3: 1146ms
Line     73 (17:53:52):: * 4: 1145ms
Line     74 (17:53:52):: * 5: 1146ms
Line     75 (17:53:52):: *----------------------------------------------------------
Line     76 (17:53:52):: * Average run time: 1145ms - over 5 tests
Line     77 (17:53:52):: *********************************************************
Line     78 (17:53:52):: *********************************************************
Line     79 (17:53:52):: * TEST 8 REPORT: ON[nInfo[nLoop]] .. OFF[nInfo[nLoop]]
Line     80 (17:53:52):: * Most recent 5 runs:
Line     81 (17:53:52):: * 1: 1904ms
Line     82 (17:53:52):: * 2: 1903ms
Line     83 (17:53:52):: * 3: 1903ms
Line     84 (17:53:52):: * 4: 1904ms
Line     85 (17:53:52):: * 5: 1904ms
Line     86 (17:53:52):: *----------------------------------------------------------
Line     87 (17:53:52):: * Average run time: 1903ms - over 5 tests
Line     88 (17:53:52):: *********************************************************
Line     89 (17:53:52):: *********************************************************
Line     90 (17:53:52):: * TEST 9 REPORT: nInfo[nLoop]=TRUE .. nInfo[nLoop]=FALSE
Line     91 (17:53:52):: * Most recent 5 runs:
Line     92 (17:53:52):: * 1: 1999ms
Line     93 (17:53:52):: * 2: 1998ms
Line     94 (17:53:52):: * 3: 1998ms
Line     95 (17:53:52):: * 4: 1999ms
Line     96 (17:53:52):: * 5: 1998ms
Line     97 (17:53:52):: *----------------------------------------------------------
Line     98 (17:53:52):: * Average run time: 1998ms - over 5 tests
Line     99 (17:53:52):: *********************************************************

    It seems the timeline method is a little more accurate than the other code I received as the tests seem to be a little quicker using the timeline tests.

    I also added a test to compare ON[] OFF[] vs Var=True Var=False. It seems that ON and OFF are slightly quicker than assignment. I would guess maybe one less cycle required to do them as the difference is about 95ms over 70,000 iterations :)

    Jeff
    · Share on FacebookShare on Twitter
  • kbeattyAMX
    kbeattyAMX Junior Member
    This is good stuff Jeff! I do find my self modifying code created by others and the biggest thing I deal with is redundancy and lack of constants/variables. Ever try to modify a code that have literal strings written for every Extron Switch? It would be quicker to rewrite the code than modify it.

    On a side note... ...Have you found any differences using DEFINE_CALL compared to DEFINE_FUNCTION?
    · Share on FacebookShare on Twitter

Leave a Comment

BoldItalicStrikethroughOrdered listUnordered list
Format
SpoilerCodeQuote
Heading 2Heading 1
Emoji
:):D:(;):/:o:s:p:'(:|B):#:*<3o:)>:)
Url
Image
Align leftAlign centerAlign rightToggle HTML viewToggle full pageToggle lights
Drop image/file
Comment As ...

Categories