SharePoint 2010 comes equipped with a set of new tools to improve the monitoring of your custom applications, there are built-in functionality to check how long your operations take, how many SQL Server calls are done etc. All this is logged and can be visualized in the Developer Dashboard.
Another good thing with this is that it’s not something that just automatically is there but you can also hook yourself into the monitoring and the actual Developer Dashboard.
Monitoring your custom code
There are many cases when you run into trouble in production, due to the fact that some parts are running slow or even makes your entire farm run on its knees. This can be because you are running a SQL query that takes forever, a never-ending loop or a Http request that takes just too long. In previous versions of SharePoint you either had to write custom code to log these conditions or write to the ULS logs, I even wrote my own event logging provider once to monitor the executed code.
In SharePoint 2010 everything is executed under a so called Monitored Scope. Each scope has a set of Monitors that measures and counts calls and timings – and this is what get’s logged in the Developers Dashboard. If you take a look at the image on the right you can see that the calls are nested and each row represents a monitored scope. At the end of each scope all monitors are evaluated and if anyone of the exceeds their limits this is logged (or if you have turned on verbose logging it always is logged).
You can very easily make your own monitored scope – and I think that you should do that from now on in all your SharePoint 2010 projects. It will help you one day!
For example if I have a Web Part that is running an operation that could take some time, for example a web service call, I could write code like this to start my scope:
1: protected override void OnPreRender(EventArgs e) {
2: using (SPMonitoredScope monitoredScope =
3: new SPMonitoredScope("Long Call")) {
4: longCall();
5: }
6: base.OnPreRender(e);
7: }
.csharpcode, .csharpcode pre { font-size: small; color: black; font-family: consolas, “Courier New”, courier, monospace; background-color: #ffffff; /*white-space: pre;*/ } .csharpcode pre { margin: 0em; } .csharpcode .rem { color: #008000; } .csharpcode .kwrd { color: #0000ff; } .csharpcode .str { color: #006080; } .csharpcode .op { color: #0000c0; } .csharpcode .preproc { color: #cc6633; } .csharpcode .asp { background-color: #ffff00; } .csharpcode .html { color: #800000; } .csharpcode .attr { color: #ff0000; } .csharpcode .alt { background-color: #f4f4f4; width: 100%; margin: 0em; } .csharpcode .lnum { color: #606060; }On line 2 i create a new object of the type SPMonitoredScope and give that scope a name (“Long Call”). Inside that scope my code that might take long time is running (line 4). If the Developer Dashboard is turned on, this scope will be visible, see image below on the third line.
This is a very easy way to improve the logging of your application.
Worth noticing is that this will not work for Sandboxed applications, they run in a separate process.
Custom monitors
Just logging your scopes in the developers dashboard is one thing but you also sometimes would like to make sure that you monitor how many times this code is executed. Let’s say that you are using a web service that you pay per use of, then it would be nice to monitor how many times you are querying the web service and optionally refuse usage if it exceeds your budget.
As I said before SharePoint 2010 always adds a set of monitors to your scopes (the parent scope actually) that monitors time, SQL queries etc. And you can do the same.
All you have to do is to create a new class and inherit from ISPScopedPerformanceMonitor and then implement that interface. To get this monitor into your scope you have to pass it as a parameter to your SPMonitoredScope constructor like this:
using (SPMonitoredScope monitoredScope =
new SPMonitoredScope("Long Call", 1000, new TheMonitor())) {...}
You can pass in as many monitors as you like.
In the code above your custom monitor is TheMonitor and it could look like this:
1: public class TheMonitor: ISPScopedPerformanceMonitor{
2: static int s_times;
3: static TheMonitor() {
4: s_times = 0;
5: }
6: public TheMonitor() {
7: s_times++;
8: }
9: public void Dispose() { }
10:
11: public string Description {
12: get { return "The Monitor"; }
13: }
14:
15: public string Name {
16: get { return "TheMonitor"; }
17: }
18:
19: public string RenderValueForWeb() {
20: return string.Format("MONITOR: {0}",s_times);
21: }
22:
23: public object Value {
24: get { return s_times; }
25: }
26:
27: public bool ValueIsExcessive {
28: get { return s_times > 5; }
29: }
30: }
.csharpcode, .csharpcode pre { font-size: small; color: black; font-family: consolas, “Courier New”, courier, monospace; background-color: #ffffff; /*white-space: pre;*/ } .csharpcode pre { margin: 0em; } .csharpcode .rem { color: #008000; } .csharpcode .kwrd { color: #0000ff; } .csharpcode .str { color: #006080; } .csharpcode .op { color: #0000c0; } .csharpcode .preproc { color: #cc6633; } .csharpcode .asp { background-color: #ffff00; } .csharpcode .html { color: #800000; } .csharpcode .attr { color: #ff0000; } .csharpcode .alt { background-color: #f4f4f4; width: 100%; margin: 0em; } .csharpcode .lnum { color: #606060; }This monitor class will count each time this monitor is called (in the constructor, line 7) and if it’s called more than 5 times the threshold value has been exceeded. (Note: this implementation will not work in production and contains no threading support). At the end of each scope, when the SPMonitoredScope is disposed it will check all monitors using the ValueIsExcessive and if that method returns true it will be logged to the ULS logs.
This is an excerpt from a ULS log using the monitor above:
Entering monitored scope (Long Call)
Leaving Monitored Scope (Long Call). Execution Time=999.885180937801
____TheMonitor=15
____Execution Time=999.885180937801
.csharpcode, .csharpcode pre { font-size: small; color: black; font-family: consolas, “Courier New”, courier, monospace; background-color: #ffffff; /*white-space: pre;*/ } .csharpcode pre { margin: 0em; } .csharpcode .rem { color: #008000; } .csharpcode .kwrd { color: #0000ff; } .csharpcode .str { color: #006080; } .csharpcode .op { color: #0000c0; } .csharpcode .preproc { color: #cc6633; } .csharpcode .asp { background-color: #ffff00; } .csharpcode .html { color: #800000; } .csharpcode .attr { color: #ff0000; } .csharpcode .alt { background-color: #f4f4f4; width: 100%; margin: 0em; } .csharpcode .lnum { color: #606060; }
I hope this post inspired you to produce code that can be monitored more easily using the SharePoint 2010 built-in features.
Merry Christmas to you all!