Author Topic: Benchmarking Script Efficiency?  (Read 1149 times)

I'm using the function getRealTime() to compare start and end times of a script to figure out where things are slowing down, but I'm getting odd results like -4 and randomly skipping between almost nothing (between -4 ~ 6ms) and 16ms every second or so.

Does anyone have a better way to calculate execution time of functions?

I would go about it with a 0ms schedule if all else fails


why not getSimTime()?
because getSimTime has no time added when the engine is busy.

So, you have something like this currently?
Code: [Select]
function asdf()
{
     %start = getRealTime();
     //stuff
     echo(getRealTime()-%start);
}

Honestly I'd recommend PMing Zack0Wack0. He made an extremely accurate benchmarking script not long ago that's really useful.

So, you have something like this currently?
Exactly like that. Identical set-up.

Aside from my previous post, have you done any debugging?

Try echoing %start and getRealTime() and see what you get.

I tested the code I wrote, and got -1 a ton. I've found this to work though:

Code: [Select]
function asdf()
{
     %start = getRealTime();

     //script

     %end = getRealTime();
     echo("Clocked asdf at " @ %end-%start @ " (" @ %end @ " - " @ %start @ ")");
}

I have no idea what changes between setting it at %end and not getRealTime(), but it works for me. No negatives.

I have no idea what changes between setting it at %end and not getRealTime(), but it works for me. No negatives.
Now, I'm either getting 0ms or -16ms only.

I think your setup will work on more complicated functions that take longer to run. The functions you're running are simply so fast that you're unable to measure accurately.

I think your setup will work on more complicated functions that take longer to run. The functions you're running are simply so fast that you're unable to measure accurately.
That's not possible. This is the function ::zombieThink -- if that's executing in fractions of a millisecond I'm doing something very right.

This is the code I made for Baseplate:
Code: [Select]
function Baseplate::__benchmark__(%this,%callback) {
cancel(%this.benchmarkSchedules[%callback]);

if(%this.benchmarks[%callback] <= 0)
return call(%callback,getSimTime() - %this.benchmarkStart[%callback]);

%this.benchmarks[%callback]--;
%this.benchmarkSchedules[%callback] = %this.schedule(0,"__benchmark__",%callback);

call(%callback);
}
function Baseplate::benchmark(%this,%callback,%times) {
if(isEventPending(%this.benchmarkSchedules[%callback]) || %times < 1 || !isFunction(%callback))
return %this;

%this.benchmarkStart[%callback] = getSimTime();
%this.benchmarks[%callback] = %times;
%this.benchmarkSchedules[%callback] = %this.schedule(0,"__benchmark__",%callback);
}
You use it like so:
Code: [Select]
function test1(%time) {
if(%time) // completed
echo(%time / 300);
else {
// do something to benchmark
}
}

_.benchmark(test1, 300); // benchmark the test1 function 300 times
You'll notice it's tested 300 times, this is to keep a consistent amount. To find the average of calling the function once, you would divide it by the number of tests.

Firstly, TorqueScript is going to work one of these ways, but I'm not sure which:

  • Event loop. Each task is given a priority. Say I start a schedule for 20ms but I also have the main task, it would do both of them at once by balancing them by priority.
  • Threaded. Each task is executed in a completely different thread. Starting a schedule would put it in a completely different thread in order to make sure the main task isn't blocked nor does it block the scheduled task.


Currently you're running it in the main task, which for either of the above means it's going to be low priority. Putting it in it's own task will ensure the highest accuracy. As to why you're getting negative numbers.. I have no clue, it doesn't happen to me when I mirror your code.

I'm using the function getRealTime() to compare start and end times of a script to figure out where things are slowing down, but I'm getting odd results like -4 and randomly skipping between almost nothing (between -4 ~ 6ms) and 16ms every second or so.

Does anyone have a better way to calculate execution time of functions?
There is no "real" way, since torque thinks that all script element takes exactly 0 milliseconds, which results in thousands of tiny small and sometimes very large jumps in the simtime and other things. This results in non-accurate time estimations, and the more functions going on at any given time, no matter how simple the function is, causes "jumps" in the time, resulting in screwy results.
« Last Edit: February 10, 2012, 04:35:34 PM by Ipquarx »

There is no "real" way, since torque thinks that all script element takes exactly 0 milliseconds, which results in thousands of tiny small and sometimes very large jumps in the simtime and other things. This results in non-accurate time estimations, and the more functions going on at any given time, no matter how simple the function is, causes "jumps" in the time, resulting in screwy results.
getRealTime gets it's data from your system, not Blockland.