{"id":1793,"date":"2015-07-31T21:23:51","date_gmt":"2015-07-31T20:23:51","guid":{"rendered":"http:\/\/www.stuartroberts.net\/?p=1793"},"modified":"2020-03-25T16:36:01","modified_gmt":"2020-03-25T16:36:01","slug":"performance-monitoring-class","status":"publish","type":"post","link":"https:\/\/www.stuartroberts.net\/index.php\/2015\/07\/31\/performance-monitoring-class\/","title":{"rendered":"Performance Monitoring Class"},"content":{"rendered":"\n<p>Thought I&#8217;d share a class I use for performance monitoring to help identify areas of code that are causing bottlenecks or take a lengthy time to execute.<\/p>\n\n\n\n<p>In SharePoint we can use the <em>SPMonitoredScope<\/em> class to wrap areas of code that we want to be monitored.<\/p>\n\n\n<div class=\"wp-block-syntaxhighlighter-code \"><pre class=\"brush: csharp; title: ; notranslate\" title=\"\">\nusing (new SPMonitoredScope(&quot;SharePoint Performance&quot;))\n{\n \/\/ SharePoint related code\n \/\/\n}\n<\/pre><\/div>\n\n\n<p>This will output performance logging statistics to the developer dashboard (if enabled) and to the ULS.<\/p>\n\n\n\n<p>For general SharePoint performance logging, <em>SPMonitoredScope<\/em> is ideal but it only logs methods calls to the SharePoint databases. The class I developed allows you to monitor any method, whether it&#8217;s SharePoint related or not.<br><br>Areas you might use the custom performance monitoring class would include calls to a custom database, web services or any potentially long running method calls.<\/p>\n\n\n\n<!--more-->\n\n\n\n<p>Click <a title=\"Performance Monitor Class\" href=\"http:\/\/www.stuartroberts.net\/downloads\/PerformanceMonitor.zip\">here<\/a> to download the performance monitoring class.<\/p>\n\n\n\n<p>The class has the following public methods:<\/p>\n\n\n\n<p>EnterMethodBlock<br>Call this to initiate monitoring for the current method.<\/p>\n\n\n\n<p>EndMethodBlock<br>Call this to end monitoring of the current method.<\/p>\n\n\n\n<p>LogPerformanceDetails<br>Call this to log performance details for the current execution point of the executing method.<\/p>\n\n\n\n<p>EndMonitoring<br>Call this to end monitoring and log performance details to the configured logger, effectively resets all monitoring counters for the current thread.<\/p>\n\n\n\n<p>ResetMonitor<br>Call this to end monitoring, similar to EndMonitoring but without writing anything to the configured logger.<\/p>\n\n\n\n<p>An example usage of the class is:<\/p>\n\n\n<div class=\"wp-block-syntaxhighlighter-code \"><pre class=\"brush: csharp; title: ; notranslate\" title=\"\">\nprivate void UpdateDatabase()\n{\n PerformanceMonitor.EnterMethodBlock();\n \n \/\/ code that updates a custom database table\n \/\/\n \/\/\n PerformanceMonitor.LogPerformanceDetails(&quot;Post update&quot;);\n \n \/\/ Process table rows\n \/\/\n \/\/\n PerformanceMonitor.LogPerformanceDetails(&quot;Post process&quot;);\n \n PerformanceMonitor.EndMethodBlock();\n}\n<\/pre><\/div>\n\n\n<p>Checking the output, to whereever you configure the log4net component of the class to write to, you&#8217;ll see entries similar to:<\/p>\n\n\n\n<p>&#8220;7 &#8216;UpdateDatabaseClassName&#8217; &#8216;UpdateDatabase&#8217; &#8216;Enter&#8217; method elapsed time: 1.0001 Overall elapsed time: 1.0001&#8221;<br>&#8220;7 &#8216;UpdateDatabaseClassName&#8217; &#8216;UpdateDatabase&#8217; &#8216;Post update&#8217; method elapsed time: 1577.1447 Overall elapsed time: 1579.1449&#8221;<br>&#8220;7 &#8216;UpdateDatabaseClassName&#8217; &#8216;UpdateDatabase&#8217; &#8216;Post process&#8217; method elapsed time: 2002.1901 Overall elapsed time: 2002.1903&#8221;<br>&#8220;7 &#8216;UpdateDatabaseClassName&#8217; &#8216;UpdateDatabase&#8217; &#8216;Exit&#8217; method elapsed time: 2008.1907 Overall elapsed time: 2010.1909&#8221;<\/p>\n\n\n\n<p>Each performance entry writes the current thread id, (in this example it&#8217;s 7), the name of the class and method name executing and then performance time data.<\/p>\n\n\n\n<p>So from the above, it&#8217;s easy to identify that the database update part of the UpdateDatabase method is taking 1.5 seconds to process and the processing of table rows half a second.<\/p>\n\n\n\n<p>The above example is only monitoring a single method, whereas in the majority of cases, you&#8217;d have multiple methods being called and monitored. When doing this, add a call to EndMonitoring at the logical point where the code you want to monitor has completed.<\/p>\n\n\n<div class=\"wp-block-syntaxhighlighter-code \"><pre class=\"brush: csharp; title: ; notranslate\" title=\"\">\nprivate void Process()\n{\n PerformanceMonitor.EnterMethodBlock();\n \n DataTable data = GetData();\n UpdateDatabase(data);\n \n PerformanceMonitor.EndMethodBlock();\n PerformanceMonitor.EndMonitoring();\n}\n\nprivate DataTable GetData()\n{\n PerformanceMonitor.EnterMethodBlock();\n \n DataTable data\n \/\/ populate data variable\n \/\/\n PerformanceMonitor.LogPerformanceDetails(&quot;Got data&quot;);\n \n PerformanceMonitor.EndMonitoring();\n \n return data;\n}\n\nprivate void UpdateDatabase(DataTable data)\n{\n PerformanceMonitor.EnterMethodBlock();\n \n \/\/ code that updates a custom database table\n \/\/\n \/\/\n PerformanceMonitor.LogPerformanceDetails(&quot;Post update&quot;);\n \n PerformanceMonitor.EndMonitoring();\n}\n<\/pre><\/div>\n\n\n<p>Click <a title=\"Performance Monitor Class\" href=\"http:\/\/www.stuartroberts.net\/downloads\/PerformanceMonitor.zip\">here<\/a> to download the performance monitoring class.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Thought I&#8217;d share a class I use for performance monitoring to help identify areas of code that are causing bottlenecks or take a lengthy time to execute. In SharePoint we can use the SPMonitoredScope class to wrap areas of code &hellip; <a href=\"https:\/\/www.stuartroberts.net\/index.php\/2015\/07\/31\/performance-monitoring-class\/\">Continue reading <span class=\"meta-nav\">&rarr;<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_mi_skip_tracking":false,"jetpack_post_was_ever_published":false,"jetpack_publicize_message":"","jetpack_is_tweetstorm":false,"jetpack_publicize_feature_enabled":true,"jetpack_social_post_already_shared":true,"jetpack_social_options":[]},"categories":[3],"tags":[70,81],"jetpack_publicize_connections":[],"aioseo_notices":[],"jetpack_featured_media_url":"","jetpack_sharing_enabled":true,"jetpack_shortlink":"https:\/\/wp.me\/plx2I-sV","_links":{"self":[{"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/posts\/1793"}],"collection":[{"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/comments?post=1793"}],"version-history":[{"count":6,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/posts\/1793\/revisions"}],"predecessor-version":[{"id":1873,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/posts\/1793\/revisions\/1873"}],"wp:attachment":[{"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/media?parent=1793"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/categories?post=1793"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.stuartroberts.net\/index.php\/wp-json\/wp\/v2\/tags?post=1793"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}