Code Performance With Anonymous Methods
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) Total 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, 2010
Code Performance With Anonymous Methods
Post titled "Code Performance With Anonymous Methods"