{"id":2525,"date":"2007-08-24T15:44:00","date_gmt":"2007-08-24T15:44:00","guid":{"rendered":"https:\/\/test.simple-talk.com\/uncategorized\/simple-code-performance-testing\/"},"modified":"2016-07-28T10:49:08","modified_gmt":"2016-07-28T10:49:08","slug":"simple-code-performance-testing","status":"publish","type":"post","link":"https:\/\/www.red-gate.com\/simple-talk\/blogs\/simple-code-performance-testing\/","title":{"rendered":"Simple Code Performance Testing"},"content":{"rendered":"<p>After posting <a href=\"https:\/\/www.simple-talk.com\/community\/blogs\/damon_armstrong\/archive\/2007\/08\/22\/35160.aspx\">Performance: Caching vs. Reading from an In-Memory XML Document<\/a>, there have been some questions about how I actually do the performance testing.&#160; My approach to performance testing is really simple&#8230; I just write some code, run that code in a big for loop, and time how long it takes to run through all of those iterations.&#160; Nothing too complicated.&#160; Calculating the speed of the operation becomes a simple matter of (iterations \/ time).&#160; I&#8217;ve packaged this testing routine into a class I call the <strong>PerformanceTimer<\/strong> class, which simplifies things even more.&#160; The code for the class follows, and an example of how to use the class to test a routine follows even further down.<\/p>\n<\/p>\n<hr \/>\n<p>using&#160;System; <\/p>\n<p>namespace&#160;Rebel.Performance <br \/>{ <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Delegate&#160;to&#160;a&#160;testing&#160;method <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;public&#160;delegate&#160;void&#160;TestingMethodDelegate(int&#160;iterations); <\/p>\n<p>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Executes&#160;a&#160;testing&#160;method&#160;and&#160;stores&#160;execution&#160;duration <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;public&#160;class&#160;PerformanceTimer <br \/>&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Property&#160;backer&#160;for&#160;the&#160;ExecutionSpan&#160;property <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;private&#160;TimeSpan&#160;_propExecutionSpan; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Property&#160;backer&#160;for&#160;the&#160;Iterations&#160;property <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;private&#160;int&#160;_propIterations; <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Duration&#160;of&#160;testing&#160;method&#160;execution <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;public&#160;TimeSpan&#160;ExecutionSpan <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;get&#160;{&#160;return&#160;_propExecutionSpan;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;private&#160;set&#160;{&#160;_propExecutionSpan&#160;=&#160;value;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Number&#160;of&#160;iterations&#160;for&#160;the&#160;test <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;public&#160;int&#160;Iterations <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;get&#160;{&#160;return&#160;_propIterations;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;private&#160;set&#160;{&#160;_propIterations&#160;=&#160;value;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Executes&#160;testing&#160;method&#160;and&#160;determines&#160;execution&#160;duration <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;param&#160;name=&#8221;testingMethod&#8221;&gt;Delegate&#160;to&#160;the&#160;testing&#160;method&lt;\/param&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;public&#160;void&#160;Run(int&#160;iterations,&#160;TestingMethodDelegate&#160;testingMethod) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;Iterations&#160;=&#160;iterations; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;long&#160;startTime,&#160;endTime; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;startTime&#160;=&#160;DateTime.Now.Ticks; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;testingMethod.Invoke(Iterations); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;endTime&#160;=&#160;DateTime.Now.Ticks; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;ExecutionSpan&#160;=&#160;new&#160;TimeSpan(endTime&#160;-&#160;startTime); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Number&#160;of&#160;iterations&#160;per&#160;second <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;public&#160;double&#160;IterationsPerSecond <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;get <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;return&#160;(Iterations&#160;\/&#160;ExecutionSpan.TotalSeconds); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Number&#160;of&#160;iterations&#160;per&#160;millisecond <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;public&#160;double&#160;IterationsPerMillisecond <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;get <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;return&#160;(Iterations&#160;\/&#160;ExecutionSpan.TotalMilliseconds); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;}&#160;\/\/class <\/p>\n<p>}&#160;\/\/namespace<\/p>\n<\/p>\n<hr \/>\n<p>So that&#8217;s the class, but how do you use it?&#160; Here&#8217;s a simple test application that uses the <strong>PerformanceTimer<\/strong> class to check the speed of concatenation operations.&#160; You&#8217;ve always heard that using a StringBuilder to build a string is faster than repeatedly concatenating a string directly?&#160; Here&#8217;s a chance to actually prove it.&#160;&#160;&#160; <\/p>\n<\/p>\n<hr \/>\n<p>using&#160;System; <br \/>using&#160;System.Text; <br \/>using&#160;Rebel.Performance; <\/p>\n<p>namespace&#160;Rebel.PerformanceTest <br \/>{ <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Console&#160;Application <br \/>&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;class&#160;Program <br \/>&#160;&#160;&#160;&#160;{ <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;static&#160;void&#160;Main(string[]&#160;args) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;PerformanceTimer&#160;timer&#160;=&#160;new&#160;PerformanceTimer(); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;int&#160;iterations&#160;=&#160;100000; <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/Run&#160;TestA <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;timer.Run(iterations,&#160;new&#160;TestingMethodDelegate(TestMethodA)); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;Console.WriteLine(timer.IterationsPerMillisecond); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/Run&#160;TestB <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;timer.Run(iterations,&#160;new&#160;TestingMethodDelegate(TestMethodB)); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;Console.WriteLine(timer.IterationsPerMillisecond); <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;Console.ReadLine(); <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Concatenation&#160;using&#160;a&#160;StringBuilder <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;static&#160;void&#160;TestMethodA(int&#160;iterations) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;StringBuilder&#160;s&#160;=&#160;new&#160;StringBuilder(); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;for&#160;(int&#160;i&#160;=&#160;0;&#160;i&#160;&lt;&#160;iterations;&#160;i++) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;s.Append(&#8220;A&#8221;); <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&#160;&#160;Direct&#160;concatenation <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;\/\/\/&#160;&lt;\/summary&gt; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;static&#160;void&#160;TestMethodB(int&#160;iterations) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;string&#160;s&#160;=&#160;&#8221;&#8221;; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;for&#160;(int&#160;i&#160;=&#160;0;&#160;i&#160;&lt;&#160;iterations;&#160;i++) <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;{ <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;s&#160;+=&#160;&#8221;A&#8221;; <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <br \/>&#160;&#160;&#160;&#160;&#160;&#160;&#160;&#160;} <\/p>\n<p>&#160;&#160;&#160;&#160;}&#160;\/\/class <\/p>\n<p>}&#160;\/\/namespace  <\/p>\n<hr \/>\n<p><strong>WARNING<\/strong>: You will want to use as large of an iteration count as possible when testing.&#160; This performance testing approach does the &#8220;best&#8221; it can when calculating exact start and end times, so some fluctuations are bound to occur when capturing the start and end times.&#160; When they do, the fluctuations throw off the calculations.&#160; Larger iteration counts spread out the effect of the fluctuations and minimize the error.&#160; Think of it this way:&#160; if you are off by 1 in 10, then you have a 10% error.&#160; If you are off by 1 in 10000, you have a 0.01% error.  <\/p>\n<hr \/>\n<p>On my machine, the StringBuilder operates at 14629 iterations \/ second and the direct concatenation approach runs at 13 iterations \/ second.&#160; Pretty significant difference.&#160;<\/p>\n","protected":false},"excerpt":{"rendered":"<p>After posting Performance: Caching vs. Reading from an In-Memory XML Document, there have been some questions about how I actually do the performance testing.&#160; My approach to performance testing is really simple&#8230; I just write some code, run that code in a big for loop, and time how long it takes to run through all&#8230;&hellip;<\/p>\n","protected":false},"author":46738,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[2],"tags":[],"coauthors":[],"class_list":["post-2525","post","type-post","status-publish","format-standard","hentry","category-blogs"],"acf":[],"_links":{"self":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/2525","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/users\/46738"}],"replies":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/comments?post=2525"}],"version-history":[{"count":2,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/2525\/revisions"}],"predecessor-version":[{"id":41546,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/2525\/revisions\/41546"}],"wp:attachment":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/media?parent=2525"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/categories?post=2525"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/tags?post=2525"},{"taxonomy":"author","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/coauthors?post=2525"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}