Measuring Speed With Anonymous Functions

I'm sure that there are many libraries available to help measure the execution of time inside of an application but I spent some time the other day writing a quick class to help me time segments of code.

The idea was to use an Anonymous Method to wrap a section of code with a Stopwatch to check the total time of execution. Additionally, since methods could be Anonymous, you could nest the measurements to see how long specific sections would take.

Anyways, here is some source code to play around with.

/// <summary>
/// Simple measuring of sections of code
/// </summary>
public class CodeBlockTimer {

    #region Private Fields

    //holds the current time for this measurement
    private Stopwatch _OverallTime;

    //container for the measured code sections
    private List<object> _Blocks = new List<object>();

    //the nested level for the code block
    private int _Level = 0;

    #endregion

    #region Methods

    /// <summary>
    /// Stops this code block timer
    /// </summary>
    public void Stop() {
        this._OverallTime.Stop();
    }

    /// <summary>
    /// Adds a block of code to measure
    /// </summary>
    public void Measure(Action block) {
        this.Measure(block.Method.Name, block);
    }

    /// <summary>
    /// Adds a block of code to measure with a defined name
    /// </summary>
    public void Measure(string identity, Action block) {

        //start the overall timer if needed
        if (this._OverallTime == null) {
            this._OverallTime = Stopwatch.StartNew();
        }
        //check and make sure this timer wasn't already stopped
        else if (!this._OverallTime.IsRunning) {
            throw new InvalidOperationException(
                "This CodeBlockTimer has already been stopped" +
        "and cannot measure additional code blocks."
                );
        }

        //create the container
        _StartBlock start = new _StartBlock(identity, this._Level++);
        _EndBlock end = new _EndBlock(start);

        //run this section of code
        this._Blocks.Add(start);
        start.Timer = Stopwatch.StartNew();
        block();
        start.Timer.Stop();
        this._Blocks.Add(end);

        //and revert the level
        this._Level--;

    }

    /// <summary>
    /// Writes the results to the Console
    /// </summary>
    public void ToConsole() {

        //make sure all of the jobs have finished
        if (this._Level > 0) {
            throw new InvalidOperationException(
                "Cannot report the final summary until all" +
        "code blocks have completed."
                );
        }

        //stop the overall timer
        if (this._OverallTime.IsRunning) {
            this._OverallTime.Stop();
        }

        //showing code groups
        Func<int, string> treeLine = (count) => {
            string start = string.Empty;
            for (var i = 0; i < count; i++) {
                start = string.Concat(start, "|  ");
            }
            return start;
        };

        //display each code block
        foreach (object item in this._Blocks) {

            //if this is a starting block, show the work has started
            if (item is _StartBlock) {
                _StartBlock block = item as _StartBlock;
                Console.WriteLine(
                    "{0}[Begin] {1}: {2}",
                    treeLine(block.Level),
                    block.Identity,
                    block.Level
                    );
            }
            //if this is the closing block, display the timer result
            else if (item is _EndBlock) {
                _EndBlock block = item as _EndBlock;
                Console.WriteLine(
                    "{0}[End] {1}: {2} ({3})",
                    treeLine(block.StartingBlock.Level),
                    block.StartingBlock.Identity,
                    block.StartingBlock.Level,
                    block.StartingBlock.ToTimeString()
                    );
            }

        }

        //and display the summary
        Console.WriteLine(
            "\nTotal Blocks: {0}\nTotal Time: {1}", 
            this._Blocks.Where(item => item is _StartBlock).Count(),
            CodeBlockTimer._ToTimeString(this._OverallTime.ElapsedMilliseconds)
            );
    }

    #endregion

    #region Static Methods

    //creates a meaningful time string from some milliseconds
    private static string _ToTimeString(long ms) {
        if (ms > 60000) {
            return string.Format("{0:0.0}min", (double)ms / 60000d);
        }
        else if (ms > 1000) {
            return string.Format("{0:0.0}sec", (double)ms / 1000d);
        }
        else {
            return string.Format("{0}ms", ms);
        }
    }

    #endregion

    #region Timing Classes

    //the marker for the start of a code block
    private class _StartBlock {

        //starts a new block to check the starting time
        public _StartBlock(string identity, int level) {
            this.Identity = identity;
            this.Level = level;
        }

        //the identifying name for this code block
        public string Identity { get; private set; }

        //the level this starts at
        public int Level { get; private set; }

        //the timer for this code block
        public Stopwatch Timer { get; set; }

        //provides a meaningful time value
        public string ToTimeString() {
            return CodeBlockTimer._ToTimeString(this.Timer.ElapsedMilliseconds);
        }
    }

    //marker for the finishing of a code block
    private class _EndBlock {

        //starts a new block to check the ending time time
        public _EndBlock(_StartBlock start) {
            this.StartingBlock = start;
        }

        //the open block this code was started in
        public _StartBlock StartingBlock { get; private set; }
    }

    #endregion

}

You can use the code inline with existing code to measure sections of the code. If you are using an existing method then the name will automatically appear in the final report. Otherwise you can use the default name or provide your own identity (which can help provide meaningful names for Anonymous Methods).

//create a monitor
CodeBlockTimer monitor = new CodeBlockTimer();

//start measuring a block
monitor.Measure("First Method", () => {

    //simulate execution time
    Thread.Sleep(300);

    //measure a block without an identity
    monitor.Measure(() => {
        Thread.Sleep(500);

        //measure a defined method
        monitor.Measure(DoSomething);
    });

    //provide an identity for an anonymoure method
    monitor.Measure("Quick Call", () => {
        Thread.Sleep(250);
    });

    //more simulated execution time
    Thread.Sleep(300);

});

//stop measuring the timer (or simply call ToConsole())
monitor.Stop();

//Display the results of the method to the console
monitor.ToConsole();

And the results...

[Begin] First Method: 0
|  [Begin] <Main>b__1: 1
|  |  [Begin] DoSomething: 2
|  |  [End] DoSomething: 2 (1000ms)
|  [End] <Main>b__1: 1 (1.5sec)
|  [Begin] Quick Call: 1
|  [End] Quick Call: 1 (250ms)
[End] First Method: 0 (2.4sec)

Blocks: 4,  Total Time: 2.4sec

Anyways, I'm sure there is a hundred other ways you could get better results -- but this might be good enough for small quick measurements.

November 18, 2009

Measuring Speed With Anonymous Functions

Using Anonymous Functions to measure blocks of code.