Export (0) Print
Expand All
Expand Minimize

Debugging and Logging Capabilities in SharePoint 2010

SharePoint 2010

Summary:  Learn about the new logging and debugging capabilities in SharePoint Foundation 2010 that enable developers to build more reliable and testable solutions.

Microsoft SharePoint 2010 is a very extensible product that developers can customize to suit various business needs. Because SharePoint is based on Microsoft ASP.NET, it provides developers with the same debugging and logging options that are available to traditional ASP.NET websites. In addition to what ASP.NET provides, SharePoint 2010 introduces additional options to assist developers in monitoring and troubleshooting applications in the areas of debugging and logging.

This article touches on various debugging and logging points and techniques that developers can use in their custom SharePoint 2010 applications.

What's New in SharePoint 2010 for Logging and Debugging

The best applications contain a good measure of logging to assist developers in tracking down errors when things do not go as they were designed or when unexpected things occur. Microsoft Office SharePoint Server 2007 offered developers all the tools that were available in ASP.NET, such as the debug and trace log. Developers could also write to the SharePoint log, known as the Unified Logging Service (ULS), but it required some extra work to write directly to the log files.

Microsoft added more logging and debugging capabilities to SharePoint 2010 to help developers include additional monitoring and troubleshooting to their custom applications. This article addresses the following new areas in SharePoint 2010:

  • Correlation tokens

  • Logging database

  • Custom error pages

  • Developer Dashboard

Every server running Windows SharePoint Services 3.0 and Office SharePoint Server 2007 wrote logging information to the ULS log files and server event log. The ULS log files, found in the {SharePoint Root}\LOGS folder on each server running SharePoint in the farm, could contain quite a bit of information, depending on how the diagnostic log throttling was configured. Although more logging detail is usually favored over less detail, it can be challenging to find a specific entry in the log files. SharePoint 2010 improves on this task of finding specific log entries by assigning some uniqueness to each log entry. This uniqueness, known as a correlation token, is a GUID that is presented to the user when an error occurs. An administrator or developer can then take this GUID string in the error and use it in searching for a specific entry in the log file. This speeds the process of finding entries in the log files for tracking down specific incidents.

The ULS can also be configured to determine how much detail is included in the log files and event log, based on specific criteria. The article Configure diagnostic logging (SharePoint Foundation 2010) (Microsoft TechNet) demonstrates how to configure the diagnostic logging in SharePoint 2010.

SharePoint Logging Database

Another change Microsoft introduced is a new database that contains all logging information for all servers in the farm. This is done through the use of a few new timer jobs. After these jobs are enabled (they are all disabled by default), SharePoint inserts diagnostic logging data into a new Microsoft SQL Server database. The following are the new timer jobs:

  • Diagnostic Data Provider: Event Log

  • Diagnostic Data Provider: Performance Counters - Database Servers

  • Diagnostic Data Provider: Performance Counters - Web Front Ends

  • Diagnostic Data Provider: SQL Blocking Queries

  • Diagnostic Data Provider: SQL DMV

  • Diagnostic Data Provider: SQL Memory DMV

  • Diagnostic Data Provider: Trace Log

Details for each of these timer jobs are documented in Timer Job Reference (SharePoint Server 2010). One of the biggest advantages to enabling these jobs is that all the various logs are aggregated into a single location that can be queried from various sources. The contents of this logging database could even be exposed by using Microsoft Business Connectivity Services (BCS) external content types and lists.

Reading the SharePoint ULS Logs

In addition to the new logging database in SharePoint 2010, developers can also analyze the raw SharePoint log files that are created in the {SharePoint Root}\LOGS folder on each server. When developing solutions, developers typically work in an isolated environment where everything is installed on a single server instead of on a farm consisting of various servers. The log files are simply large fixed-width delimited text files that can be read and searched by using any text editor.

In addition to searching raw text files, quite a few developers have published various utilities that assist in reading the SharePoint log files. A quick search for SharePoint ULS viewer yields numerous resources. Some of these utilities include notifications and ways to make searching and filtering for specific criteria much easier than by using a standard text editor.

Writing to the SharePoint ULS Logs

Reading from the SharePoint ULS logs is helpful when troubleshooting SharePoint generated messages. But one thing developers really need is the ability to write their own messages to the log files. Microsoft made it much easier to write to the log files in SharePoint 2010 by using the SPDiagnosticsService class, as shown in the following example.

try{
  ...
} catch (Exception ex) {
  SPDiagnosticsService.Local.WriteTrace(0, new SPDiagnosticsCategory("MSDN", TraceSeverity.Unexpected, EventSeverity.Error), TraceSeverity.Unexpected, ex.Message, ex.StackTrace);
}

The previous code snippet will write the exception details to the SharePoint ULS log. Upon inspecting the entry that is added, developers will notice that the entry for the Product column is Unknown. This is the default behavior of the SPDiagnosticsService class. To add custom product names, developers can implement their own diagnostics service by using the SPDiagnosticsServiceBase class. Unfortunately, interacting with a custom SPDiagnosticsService is available only in fully trusted farm solutions and not within sandboxed solutions. To write to the ULS logs by using the SPDiagnosticsService class from the sandbox, developers can create a full trust proxy that the sandboxed solutions can call into. The next two sections describe how to write to the SharePoint ULS logs.

In addition to writing a custom SPDiagnosticsService class, the Microsoft patterns & practices group has released the Developing Applications for SharePoint 2010 guidance package, which includes a SharePoint logger. Developers should consider all these approaches when building custom applications.

Creating a Custom Logging Service

Creating a custom logging service in a custom application involves creating a new implementation of the SPDiagnosticsServiceBase class, overwriting a single method, and providing a few ways to write to the log files.

The following example shows how to add a new class to a non-sandboxed solution and have the class inherit from the SPDiagnosticsServiceBase class.

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using Microsoft.SharePoint.Administration;

namespace MSDN.SharePoint.Samples.WriteToUls {
  public class LoggingService : SPDiagnosticsServiceBase { 
    private LoggingService() : 
      base("MSDN Logging Service", SPFarm.Local) { }
  }
}

Next, implement the ProvideAreas method that will register the product name and logging categories available, as shown in the following example.

public const string MSDN_INFO = "MSDN Info";
public const string MSDN_ERROR = "MSDN Error";
private static string PRODUCT_DIAGNOSTIC_NAME = "MSDN Sample";

protected override IEnumerable<SPDiagnosticsArea> ProvideAreas() {
  List<SPDiagnosticsArea> areas = new List<SPDiagnosticsArea>{
    new SPDiagnosticsArea(PRODUCT_DIAGNOSTIC_NAME, new List<SPDiagnosticsCategory>{
      new SPDiagnosticsCategory(MSDN_INFO, TraceSeverity.Verbose, EventSeverity.Information),
      new SPDiagnosticsCategory(MSDN_ERROR, TraceSeverity.Unexpected, EventSeverity.Warning),
    })
  };

  return areas;
}

The following example shows the last step, which is to make the custom logging service easy to use by adding a few static methods that can be called from custom components, such as Web Parts.

private static LoggingService _current;
public static LoggingService Current {
  get {
    if (_current == null)
      _current = new LoggingService();
    return _current;
  }
}

public static void LogMessage(string categoryName, string message) {
  SPDiagnosticsCategory category = 
  LoggingService.Current.Areas[PRODUCT_DIAGNOSTIC_NAME].Categories[categoryName];
  LoggingService.Current.WriteTrace(0, category, TraceSeverity.Verbose, message);
}

public static void LogError(string categoryName, string message) {
  SPDiagnosticsCategory category = 
  LoggingService.Current.Areas[PRODUCT_DIAGNOSTIC_NAME].Categories[categoryName];
  LoggingService.Current.WriteTrace(0, category, TraceSeverity.Unexpected, message);
}

Test the logger by adding a custom component to the project, such as a Web Part, and call the logging service, as shown in the following example.

public class WriteToUlsFarmSolutionWebPart : WebPart {
  protected override void CreateChildControls() {
    Button logInfoButton = new Button { Text = "log info entry" };
    logInfoButton.Click += (sender, e) => 
      LoggingService.LogMessage(LoggingService.MSDN_INFO, "Sample info message.");
    this.Controls.Add(logInfoButton);

    Button logErrorButton = new Button { Text = "log error entry" };
    logErrorButton.Click += (sender, e) =>
      LoggingService.LogMessage(LoggingService.MSDN_ERROR, "Sample error message.");
    this.Controls.Add(logErrorButton);
  }
}

When the previous code is run by clicking one of the buttons in the Web Part, a new entry is added to the SharePoint log file by using the product name MSDN Sample and one of the new categories.

Writing to the ULS Logs from Sandboxed Solutions

Unfortunately, writing to the ULS logs directly is not possible from within a sandboxed solution. This is because the sandboxed solution does not have access to the logging service from the isolated user code service. However, developers can create a full trust proxy that is deployed as a farm solution, and then any sandboxed solution could take advantage of this full trust proxy. For a detailed walkthrough about creating a full trust proxy, see How To: Create and Register a Sandbox Proxy.

Create a farm solution by using the SharePoint development tools in Microsoft Visual Studio 2010, and create the same SPDiagnosticsServiceBase logging class that was created previously. The next step is to create the proxy that will call the logging service.

Add another class to the project that will take the proxy operation arguments, as shown in the following example.

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using Microsoft.SharePoint.UserCode;

namespace MSDN.SharePoint.Samples.WriteToUls {
  [Serializable]
  public class LoggingMessageProxyArguments : SPProxyOperationArgs {
    public string MessageCategoryName { get; set; }
    public string MessageContents { get; set; }

    public static string LoggingProxyOperationTypeName {
      get {
        return "LoggingProxy.LoggingMessageProxyOperation";
      }
    }

    public static string LoggingProxyAssemblyName {
      get {
        return "MSDN.SharePoint.Samples.WriteToUlsSandboxSolution.Proxy, Version=1.0.0.0, Culture=neutral, PublicKeyToken=[INSERT PROJECT'S PUBLICKEYTOKEN HERE]";
      }
    }
  }
}

Next, add another class to the project that performs the fully trusted operation, as shown in the following example.

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using Microsoft.SharePoint.UserCode;

namespace MSDN.SharePoint.Samples.WriteToUls {
  public class LoggingMessageProxyOperation : SPProxyOperation {
    public override object Execute(SPProxyOperationArgs args) {
      LoggingMessageProxyArguments proxyArguments = args as LoggingMessageProxyArguments;

      string loggingCategory ;
      switch (proxyArguments.MessageCategoryName.ToLower()) {
        case LoggingService.MSDN_ERROR:
          loggingCategory = LoggingService.MSDN_ERROR;
          break;
        default:
          loggingCategory = LoggingService.MSDN_INFO;
          break;
      }

      // Do full trust action.
      LoggingService.LogMessage(loggingCategory, proxyArguments.MessageContents);
    }
  }
}

With the proxy's arguments and operation created, the last step is to register it with the user code service in the farm. This can be done by using the activated event in a farm-scoped Feature, as shown in the following example.

public class LoggingMessageProxyInstallerEventReceiver : SPFeatureReceiver {
  public override void FeatureActivated(SPFeatureReceiverProperties properties) {
    // Get proxy operation.
    LoggingMessageProxyOperation proxyOperation = new SPProxyOperationType(
                                LoggingMessageProxyArguments.LoggingProxyAssemblyName,
                                LoggingMessageProxyArguments.LoggingProxyOperationTypeName);

    SPUserCodeService ucService = SPUserCodeService.Local;
    ucService.ProxyOperationTypes.Add(proxyOperation);
    ucService.Update();
  }

  public override void FeatureDeactivating(SPFeatureReceiverProperties properties) {
    // Get proxy operation.
    LoggingMessageProxyOperation proxyOperation = new SPProxyOperationType(
                                LoggingMessageProxyArguments.LoggingProxyAssemblyName,
                                LoggingMessageProxyArguments.LoggingProxyOperationTypeName);

    // Add proxy to user code service.
    SPUserCodeService ucService = SPUserCodeService.Local;
    ucService.ProxyOperationTypes.Remove(proxyOperation);
    ucService.Update();
  }
}

After this project is deployed and the included farm-scoped Feature is activated, the proxy can be called from within a sandboxed solution. The following code shows how a Web Part that is deployed in a sandboxed solution can use the full trust proxy and write to the SharePoint 2010 ULS logs.

public class WriteToUlsSandboxSolutionWebPart : WebPart {
  protected override void CreateChildControls() {
    LoggingMessageProxyArguments loggingProxyArgs = new LoggingMessageProxyArguments();

    Button logInfoButton = new Button { Text = "log info entry" };
    logInfoButton.Click += (sender, e) => {
      loggingProxyArgs.MessageCategoryName = LoggingService.MSDN_INFO;
      loggingProxyArgs.MessageContents = "Sample info message";
      var result1 = SPUtility.ExecuteRegisteredProxyOperation(
        LoggingMessageProxyArguments.LoggingProxyAssemblyName,
        LoggingMessageProxyArguments.LoggingProxyOperationTypeName,
        loggingProxyArgs);
    };
    this.Controls.Add(logInfoButton);

    Button logErrorButton = new Button { Text = "log error entry" };
    logInfoButton.Click += (sender, e) => {
      loggingProxyArgs.MessageCategoryName = LoggingService.MSDN_ERROR;
      loggingProxyArgs.MessageContents = "Sample info message";
      var result2 = SPUtility.ExecuteRegisteredProxyOperation(
        LoggingMessageProxyArguments.LoggingProxyAssemblyName,
        LoggingMessageProxyArguments.LoggingProxyOperationTypeName,
        loggingProxyArgs);
    };
    this.Controls.Add(logErrorButton);
  }
}

For guidelines about writing the logging event and trace events to the ULS logs, see Trace and Event Log Severity Levels in the SharePoint 2010 SDK

Adding copious amounts of logging to custom projects is a good idea for developers because it helps track down problems when they occur. However, there will always be times when errors still occur that developers will have to track down. In addition, developers may want to change some of the default system pages that SharePoint 2010 uses. The following sections describe these two scenarios.

Using the Web Application web.config File

When errors occur in an ASP.NET application, they are shown either in their raw state (when the web.config file contains the element <customErrors mode="Off" />), or by using a custom error page to hide the details of the error and display a custom message (when the web.config file contains the element <customErrors mode="On" />).

The default configuration in SharePoint 2010 is to turn custom errors on and not show the details of the error. One reason for this is so users do not see unfriendly errors, and instead are presented with a more graceful error page. Another reason for not including the full details is because providing complete details of an error could be considered a security flaw as it may expose more information that should be exposed to users.

Unfortunately, the custom error messages delivered by SharePoint are sometimes not detailed enough for developers to troubleshoot the problem. When building custom solutions, it is helpful to see the full error including the specific exception, the exception message, and the complete call stack. This can be achieved easily by modifying the web application's web.config file and changing the mode in the <customErrors /> element to Off. This will display the raw ASP.NET error page for the entire web application. This process can also be automated by using a web application–scoped Feature, by implementing the Feature's activated and deactivated events to make this change, as shown in the following example.

public override void FeatureActivated(SPFeatureReceiverProperties properties) {
  SPWebApplication WebApp = (SPWebApplication)properties.Feature.Parent;
  foreach (ModificationEntry modEntry in Entries) {
    WebApp.WebConfigModifications.Add(
      CreateModification(modEntry)
    );
  }
  WebApp.WebService.ApplyWebConfigModifications();
}

public override void FeatureDeactivating(SPFeatureReceiverProperties properties) {
  SPWebApplication WebApp = (SPWebApplication)properties.Feature.Parent;
  foreach (ModificationEntry modEntry in Entries) {
    WebApp.WebConfigModifications.Remove(
      CreateModification(modEntry)
    );
  }
  WebApp.WebService.ApplyWebConfigModifications();
}

private struct ModificationEntry {
  public string Name;
  public string XPath;
  public string Value;
  public SPWebConfigModification.SPWebConfigModificationType ModType;
  // Parameterized contructor.
  public ModificationEntry(
      string Name, string XPath, string Value,
      SPWebConfigModification.SPWebConfigModificationType ModType) {
    // Intialize structure instances.
    this.Name = Name;
    this.XPath = XPath;
    this.Value = Value;
    this.ModType = ModType;
  }
}

private ModificationEntry[] Entries = {
  new ModificationEntry( 
    "mode", "configuration/system.web/customErrors", "Off", 
    SPWebConfigModification.SPWebConfigModificationType.EnsureAttribute)
 };

private SPWebConfigModification CreateModification(ModificationEntry modEntry) {
  // Create and return SPWebConfigModification object.
  SPWebConfigModification modification;
  modification = new SPWebConfigModification(modEntry.Name, modEntry.XPath);
  modification.Owner = "MSDN.SharePointDebugger";
  modification.Sequence = 0;
  modification.Type = modEntry.ModType;
  modification.Value = modEntry.Value;
  return modification;
}

Using the Layouts web.config File

You should keep in mind that folders in a web application inherit the web.config file settings from their parent folders, unless they are overwritten by a local web.config file. Specific to SharePoint 2010, the http://.../_layouts folder contains its own web.config file that has the custom errors turned on. Therefore, when creating custom application pages or troubleshooting the SharePoint 2010 application pages, developers may want to either modify the web.config located in the {SharePoint Root}\TEMPLATE\LAYOUTS folder, or add a custom web.config that turns off custom errors in the folder containing the custom application pages.

SharePoint 2010 includes numerous system application pages for things such as reporting errors, access-denied notifications, and logon and logoff pages. In earlier versions of SharePoint, these files were hard-coded. Although some were easy to change, such as the logon page that can be changed in the web.config file, others could not be changed without some very creative code.

Microsoft improved this in SharePoint 2010 by giving developers a way to retrieve the URL of a custom page, and enabling developers to create their own system application pages. This enables developers to create custom system application pages that include custom business logic or that can be branded to match the rest of the site's branding. These changes can be applied to a web application using two methods: GetMappedPage and UpdateMappedPage. A list of the available system application pages that can be changed is found in the SPWebApplication.SPCustomPage enumeration.

Changing a system master page is best implemented in the activated and deactivated events of a web application–scoped Feature. First ,create a new application page that will serve the purpose of the custom system application page. Next, create a web application–scoped Feature and implement the activated and deactivated events, as shown in the following example.

public class CustomErrorPagesEventReceiver : SPFeatureReceiver {
  public override void FeatureActivated(SPFeatureReceiverProperties properties)
  {
    SPWebApplication webApp = properties.Feature.Parent as SPWebApplication;
    if (webApp != null) {
      // Set Access Denied.
      if (!webApp.UpdateMappedPage(SPWebApplication.SPCustomPage.AccessDenied, 
          "/_layouts/CustomErrorPages/AccessDenied.aspx")) {
        throw new ApplicationException("Failed setting new access denied page mapping.");
      }

      // Set Signout.
      if (!webApp.UpdateMappedPage(SPWebApplication.SPCustomPage.Signout, 
          "/_layouts/CustomErrorPages/Signout.aspx")) {
        throw new ApplicationException("Failed setting new signout page mapping.");
      }

      // Set File Not Found.
      webApp.FileNotFoundPage = "/_layouts/1033/FileNotFound.htm";

      webApp.Update(true);
    }
  }

  public override void FeatureDeactivating(SPFeatureReceiverProperties properties)
  {
    SPWebApplication webApp = properties.Feature.Parent as SPWebApplication;
    if (webApp != null) {
      webApp.UpdateMappedPage(SPWebApplication.SPCustomPage.AccessDenied, null);
      webApp.UpdateMappedPage(SPWebApplication.SPCustomPage.Signout, null);
        webApp.FileNotFoundPage = null;
    }
  }
}

The Developer Dashboard is another new addition to SharePoint 2010 to help developers with logging and debugging custom components that are added to SharePoint pages. The Developer Dashboard can be turned on for an entire farm to get a snapshot of the activity and performance of a specific page request.

Figure 1. Developer Dashboard

Developer Dashboard

The Developer Dashboard can be very helpful in troubleshooting problematic components on a page, because a single SharePoint page can contain multiple custom components. When a page contains multiple custom components and the performance of a page is slower than desired, it can be hard to isolate which component is the root cause for the slow performance, other than by using a simple process of elimination. This is exactly the scenario the Developer Dashboard is designed to assist with.

The Developer Dashboard includes a few different categories of information. It provides details on how long it took treads to process, details on the quantity and execution duration of SQL Server database calls and Windows Communication Foundation (WCF) service calls, details on the URL, and the current user, and more.

Configuring the Developer Dashboard

By default, the Developer Dashboard is not turned on. Enabling the Developer Dashboard can be done either through the API or by using a custom Windows PowerShell script, as shown in the following example.

$contentService = [Microsoft.SharePoint.Administration.SPWebService]::ContentService
$dashboardSetting = $contentService.DeveloperDashboardSettings
$dashboardSetting.DisplayLevel = [Microsoft.SharePoint.Administration.SPDeveloperDashboardLevel]::On
$dashboardSetting.Update()

There are two different display levels available on the Developer Dashboard. The SPDeveloperDashboardLevel.On enumeration option enables the dashboard on all pages in a farm. Setting it to SPDeveloperDashboardLevel.OnDemand leaves it disabled, but adds a performance counter-like image to the top-right corner of the page. When this image is clicked, a postback is triggered that adds the Developer Dashboard to the page.

For information about the Developer Dashboard, see Using the Developer Dashboard in the SharePoint 2010 SDK.

Although the Developer Dashboard includes a considerable amount of information for SharePoint processes, developers can also add their own logging in custom components that appear in the dashboard.

Writing to the Developer Dashboard

Writing to the Developer Dashboard can be done only directly from farm solutions; sandboxed solutions cannot write to the Developer Dashboard because they are isolated in the user code process. To write to the Developer Dashboard, a custom component should be wrapped in a SPMonitoredScope object.

The following code shows how to write to the Developer Dashboard and how to create nested scopes.

public class MonitoredWebPart : WebPart {
  protected override void CreateChildControls() {
    using (SPMonitoredScope scope = new SPMonitoredScope("MonitoredWebPart.CreateChildControls")) {
      this.Controls.Add(
        new LiteralControl("Turn on the developer dashboard to see entries logged by this Web Part.");

        // Trigger a SPRequest & DB round trip.
        TriggerSpDatabaseRequest();
        TriggerSPRequestObject();

        // Simulate a delay.
        TriggerSimulatedDelay();
      );
    }
  }
  private void TriggerSpDatabaseRequest() {
    using (SPMonitoredScope scope = new SPMonitoredScope("MonitoredWebPart.TriggerSpDatabaseRequest")) {
      SPList someList = SPContext.Current.Web.Lists[0];
      int itemsinList = someList.Items.Count();
    }
  }

  private void TriggerSPRequestObject() {
    using (SPMonitoredScope scope = new SPMonitoredScope("MonitoredWebPart.TriggerSPRequestObject")) {
      using (SPSite siteCollection = new SPSite(SPContext.Current.Site.Id)) {
        string siteCollectionUrl = siteCollection.RootWeb.Url;
      }
    }
  }

  private void TriggerSimulatedDelay() {
    using (SPMonitoredScope scope = new SPMonitoredScope("MonitoredWebPart.TriggerSimulatedDelay")) {
      System.Threading.Thread.Sleep(2000);
    }
  }
}

Figure 2 shows the results of adding the Web Part shown in the previous code example to the page.

Figure 2. Writing to the Developer Dashboard

Writing to the Developer Dashboard

Adding the Developer Dashboard to Custom Master Pages

The Developer Dashboard is included in all SharePoint sites that use one of the master pages included in SharePoint 2010. When creating custom master pages, developers can add the Developer Dashboard by simply adding the following server control, ideally to the bottom of the page:

<SharePoint:DeveloperDashboard runat="server" />

When the Developer Dashboard is set to SPDeveloperDashboardLevel.OnDemand, it uses the dashboard launcher to display the icon and render the dashboard. Developers will also want to add the following control to custom master pages also:

<SharePoint:DeveloperDashboardLauncher runat="server" />

This control contains a few public properties to change the placement, text, and image used to render the control. These can be found in the DeveloperDashboardLauncher class in the SharePoint 2010 SDK.

Microsoft put a significant focus on the developer story in the latest release of SharePoint, Microsoft SharePoint 2010. In addition to the first-class developer tools included in Visual Studio 2010, Microsoft added considerable flexibility and capabilities for developers to add logging and debugging techniques to custom solutions built for SharePoint 2010. This article walks through some common logging and debugging techniques that are now available to developers when building SharePoint 2010 solutions.

Community Additions

ADD
Show:
© 2014 Microsoft