Code Racer

Introduction

Q: Want to see if one version of code usually runs faster than another?

A: Run your code inside a test harness such as the example code here to race two or more versions time and again. Along the way, declare the winners, measuring each win by the change in the llGetTime dilated script time.

Sample Results

Click Running = No to stop this script after you've seen enough ...
2007-10-25T02:33:12.806088Z

~4.237066 ms elapsed in version 1 to place at 1 by 8 of 10 votes
~10.047700 ms elapsed in version 2 to place at 2 by 8 of 10 votes
2007-10-25T02:33:15.009855Z

~3.089838 ms elapsed in version 1 to place at 1 by 44 of 100 votes
~5.549734 ms elapsed in version 2 to place at 2 by 57 of 100 votes
2007-10-25T02:33:35.422763Z

~1.333064 ms elapsed in version 1 to place at 1 by 55 of 100 votes
~3.434490 ms elapsed in version 2 to place at 2 by 64 of 100 votes
2007-10-25T02:33:56.083810Z

~0.760552 ms elapsed in version 1 to place at 1 by 49 of 100 votes
~1.922230 ms elapsed in version 2 to place at 2 by 63 of 100 votes
2007-10-25T02:34:16.564139Z

~1.981575 ms elapsed in version 1 to place at 1 by 481 of 1000 votes
~5.013962 ms elapsed in version 2 to place at 2 by 597 of 1000 votes
2007-10-25T02:37:40.371221Z

~1.475276 ms elapsed in version 1 to place at 1 by 498 of 1000 votes
~3.177954 ms elapsed in version 2 to place at 2 by 596 of 1000 votes
2007-10-25T02:41:07.869815Z

~0.773118 ms elapsed in version 1 to place at 1 by 467 of 1000 votes
~1.858705 ms elapsed in version 2 to place at 2 by 597 of 1000 votes
2007-10-25T02:44:25.003959Z

Code

// Race a few version of code in dilated script time as measured by llGetTime.
// http://wiki.secondlife.com/wiki/Code_Racer

// List every runnable version.

list theRunners = [0, 1, 2];

// Count runnable versions.

integer theRunnable;

// Count votes to place.

list theVotes;

// Sum the run times observed.

list theSums;

// Count the races that ran without time running backwards.

integer theAverageable;

// Race no code alongside the other code in order to measure overhead.

runner0()
{
}

// Race a few versions of code.

runner1()
{
    integer spinning;
    for (spinning = 0; spinning < 25; ++spinning)
        ;
}

runner2()
{
    integer spinning;
    for (spinning = 0; spinning < 50; ++spinning)
        ;
}

runner3()
{
}

runner4()
{
}

runner5()
{
}

// Run the chosen runner once.
// Run thru an equal time while choosing any runner.

run(integer runner)
{
    if (runner == 0) { runner0(); }
    if (runner == 1) { runner1(); }
    if (runner == 2) { runner2(); }
    if (runner == 3) { runner3(); }
    if (runner == 4) { runner4(); }
    if (runner == 5) { runner5(); }
}

// Start up.

startup()
{
    llOwnerSay("");
    llOwnerSay("Click Running = No to stop this script after you've seen enough ...");
    llOwnerSay(llGetTimestamp());
}

// Measure the race in calendar time elapsed since the minute began,
// if called in place of llGetTime.
//
// Note: "YYYY-MM-DDThh:mm:ss.ff..fZ" = llGetTimestamp();
// Note: 17 = 0 + llStringLength("YYYY-MM-DDThh:mm:")
// Note: -2 = -1 - llStringLength("Z")

float getTime()
{
    return (float) llGetSubString(llGetTimestamp(), 17, -2); // "ss.ff..f"
}

// Race the runners and return the times when each ran.
// Run in llGetTime dilated time or in getTime calendar time.

list eachRunnerRun()
{
    list befores = [];
    integer runnablePlus = theRunnable + 1;
    integer running;
    for (running = 0; running < runnablePlus; ++running)
    {
        integer running = llList2Integer(theRunners, running);
        befores += llGetTime();
        run(running);
    }
    return befores;
}

// Return elapsed run time per runner,
// else return [] if time ran backwards.

list getRuntimesElseNone(list befores)
{
    list runtimes = [];
    float before = llList2Float(befores, 0);
    integer timing;
    for (timing = 0; timing < theRunnable; ++timing)
    {
        float after = llList2Float(befores, timing + 1);
        float runtime = after - before;
        if (runtime < 0.0) return [];
        runtimes += runtime;
        before = after;
    }
    return runtimes;
}

// Add to a listed float.

list addFloat(list sums, integer index, float addition)
{
    list results = [];
    integer summable = llGetListLength(sums);
    integer summing;
    for (summing = 0; summing < summable; ++summing)
    {
        float result = llList2Float(sums, summing);
        if (index == summing)
        {
            result += addition;
        }
        results += result;
    }
    return results;
}

// Add to a listed integer.

list addInteger(list sums, integer index, integer addition)
{
    list results = [];
    integer summable = llGetListLength(sums);
    integer summing;
    for (summing = 0; summing < summable; ++summing)
    {
        integer result = llList2Integer(sums, summing);
        if (index == summing)
        {
            result += addition;
        }
        results += result;
    }
    return results;
}

// Race the runners once, vote to place, and sum run time per runner.

runRace()
{

    // Race the runners once.

    list runtimes = getRuntimesElseNone(eachRunnerRun());
//  llOwnerSay("[" + llDumpList2String(runtimes, ", ") + "] == runtimes");

    // Sort the runtimes into places.

    list places = llListSort(runtimes, 1, TRUE); // sort least to most
    integer placeable = llGetListLength(places); // 0 or theRunnable

    // Sum run time per runner.

    integer adding;
    for (adding = 0; adding < placeable; ++adding)
    {
        integer running = llList2Integer(theRunners, adding);
        float runtime = llList2Float(runtimes, adding);
        theSums = addFloat(theSums, running, runtime);
        ++theAverageable;

        // Vote to place at each equal runtime.

        integer placing;
        for (placing = 0; placing < placeable; ++placing)
        {
            float placed = llList2Float(places, placing);
            if (runtime == placed)
            {
                integer flat = (running * placeable) + placing;
                theVotes = addInteger(theVotes, flat, 1);
            }
        }
    }
}

// Start up a burst of races.

zeroBurst()
{
    theSums = theVotes = [];
    theRunnable = llGetListLength(theRunners);
    integer placing;
    for (placing = 0; placing < theRunnable; ++placing)
    {
        theSums += 0.0;
        integer running;
        for (running = 0; running < theRunnable; ++running)
        {
            theVotes += 0;
        }
    }
}

// Report a burst of races.

reportBurst(integer scaling)
{

    // Consider each place.

    integer placing;
    for (placing = 0; placing < theRunnable; ++placing)
    {
        list votes = llList2ListStrided(llList2List(theVotes, placing, -1), 0, -1, theRunnable);
        integer winner = llList2Integer(llListSort(votes, 1, TRUE), -1);

        // Find the winner (or the winners) of that place.

        integer running;
        for (running = 1; running < theRunnable; ++running)
        {
            integer vote4place = llList2Integer(votes, running); 
            if (vote4place == winner)
            {

                // Describe a winner.

                float summed = llList2Float(theSums, running) - llList2Float(theSums, 0);
                float average = 1000.0 * (summed / theAverageable);

                llOwnerSay("~" +
                    (string) average + " ms elapsed in version " + (string) running +
                    " to place at " + (string) placing +
                    " by " + (string) vote4place + " of " + (string) scaling + " votes"
                );
            }
        }
    }
}

// Run a few bursts of races at each scale, for indefinitely increasing scale.

runRaceRepeatedly()
{
    integer scaleable = 10;
    integer repeatable = 1; // don't bother to repeat the first burst
    while (TRUE)
    {
        integer repeating;
        for (repeating = 0; repeating < repeatable; ++repeating)
        {
            zeroBurst();

            integer scaling;
            for (scaling = 0; scaling < scaleable; ++scaling)
            {
                runRace();
                theRunners = llList2List(theRunners, -1, -1) + llList2List(theRunners, 0, -2);
            }

            llOwnerSay("");
            reportBurst(scaling);
            llOwnerSay(llGetTimestamp());
        }
        
        scaleable *= 10;
        repeatable = 3; // repeat most bursts several times
    }
}

// Race to measure relative run-time cost of multiple versions of code.
// Produce unreasonable answers when the run-time cost measured equals or exceeds 60 seconds.

default
{
    state_entry()
    {
        startup();
        runRaceRepeatedly();
    }
}

Instructions

This instrument quickly & accurately measures the run time difference between a number of fragments of code. For example, the code presented here measures the difference between the two fragments of code found inside the functions named runner1 and runner2. To measure other code, insert the code you want to compare into the runner1, runner2, runner3, etc. functions. See the source line that assigns [0, 1, 2] to theRunners? List all the runners you want to run there. Leave runner0 empty so that the harness correctly measures and subtracts out its own overhead.

Alternatives & Caveats

This instrument compares run times quickly, like 100X faster than the Efficiency Tester instrument. This instrument runs a number of fragments of code at a time, gives you immediate results and then progressively more accurate results over time, like when you slowly fetch a detailed image from the web. This instrument burns thru hugely much run time, so that it can provide immediate feedback to make work proceed when the work would otherwise be too hard & boring to attract enough volunteers.

The Efficiency Tester instrument serves a different purpose. That instrument adds accuracy to a measure of a range of observed run times in as little time as possible. By simple arithmetic, running thru 200ms for 1,000 times necessarily takes at least 200s, aka, more than 3 minutes. That instrument runs one fragment of code at a time, but then runs that fragment many many times to try and average out any distractions that may hit the server during the run. That instrument actually can measure 200ms in as little as 10 minutes, but that instrument gives you no answer at all until after 10,000 runs and no final answer until after 30,000 runs.

See the LSL Script Efficiency article for much discussion of the Efficiency Tester instrument, including recommendations on how to avoid distracting the server into spending run time running other code in parallel. Those same recommendation apply to any llGetTimestamp harness, including this instrument.

Please do try to find deserted places to run such benchmarks and remember to turn them off when you finish! Else naturally you'll be rudely lagging the sim for the other people sharing the sim with you, for however long you run the benchmark.

See Also

Functions

llGetTime - fetch the (often zeroed) dilated time in seconds and fractional seconds

llGetTimestamp - fetch the ISO 8601 "YYYY-MM-DDThh:mm:ss.ff..fZ" string that names the calendar date and time that is now

Scripts

Code Sizer - count bytes of code with perfect accuracy

Efficiency Tester - run as long as you please to count approximate milliseconds of run time with every more accuracy