Five suggestions to implement a better logging in SharePoint

Introduction

Most of the code written for SharePoint works under highly unpredictable environment. Even if your code does not produce any exceptions in the development environment, the same code might just magically fail on the production environment. That is why logging is a highly critical piece of your solution and code.

Generally, logging is a quite popular topic among the developers. Some of them like “our custom logging system”, others use already existing frameworks and, finally, the rest could end up with services provided by native operation system, e.t. Window API (Sic! No kidding!).

If you write custom code for SharePoint, here are some suggestions to improve logging part of your solution:

Suggestion #0 – Do not use a 3^rd party logging framework

Even if you stick to log4net, NLog, EventLog or System.Diagnostic.Trace, or trying to invent your own wheel, then do not ever use that stuff again.

SharePoint has its own logging system called “Unified Logging System (ULS)“. If you still wonder why would you use ULS instead your lovely logging framework, then consider the following facts:

• ULS is used by SharePoint, so if you used 3^rd part logging, you would need to consolidate logs from few different sources
• ULS can be easily configured from Central Administration as well as by PowerShell
• ULS can write to Windows Event Log without elevated privileges (!)
• ULS shrinks text log files on the hard drives (!)
• ULS does not require web.config changes/modifications (!). That’s quite important concern for multi-server farm
• SharePoint can aggregate ULS log (and not just logs..) from multiple servers to the logging data base (Usage and Health Data Collection Service Application)

Suggestion #1 – Don’t do anything for the simplest cases

By default, SharePoint catches unhandled exception and reports them to the ULS log. If you have unhandled exception, you may easily find an error and its stacktrace in the ULS logs. If you turn on the “VerboseEx” logging level, then you will see even SQL queries to the database.

You may also use ULSViewer for more convenient log viewing experience.

Meanwhile, there is an exception from that “by default” recommendation – that is about WebParts. If your custom web part failed with exception, then the end user would see just the default error page. You probably would spend more time if you had an error with misconfigured personal web part property – you just would not be able to trace and debug this error unless you logged in under that particular user. If you develop a custom webpart, then a better way might be not just show up the error, but also provide some suggestion about the possible way to fix that error.

Suggestion #2 – Use SPMonitoredScope class

SPMonitoredScope could be used as simple as that:

using (new SPMonitoredScope("My Monitored Scope"))
{
 // Do Stuff...
}

You will simple get enter/leave log records, and the time has been spent for the scope invocation. By default SPMonitoredScope has a “Verbose” logging level.

SPMonitoredScope might also help to log performance and resource usage/allocation:

using (new SPMonitoredScope("My Scope Name",1000,
 new SPRequestUsageCounter(3),
 new SPSqlQueryCounter(10)))
{
 //Do Stuff...
}

In case you reached execution time (1000 ms), or the total count of SPSite/SPWeb allocation is more than 3, or the total amount of the SQL queries is more than 10, then logging level would be promoted to “High”. Also, you would get actual values of these parameters and the actual places (by the stacktrace) where SPSite/SPWeb object had been created, and SQL queries were performed.

Probably, the most interesting fact about SPMonitoredScope is that trace is pushed to the Developer Dashboard.

If you have the following code:

using (new SPMonitoredScope("My Monitored Scope"))
{
    using (new SPMonitoredScope("My Sub-Monitored Scope"))
    {
        using (new SPMonitoredScope("My Sub-Sub-Monitored Scope"))
        {
        }

        using (new SPMonitoredScope("Another deep scope"))
        {
        }
    }
}

Then you will have that picture in the Developer Dashboard:

Suggestion #3 – Use SPDiagnosticsService to write logs

You may write to the ULS via SPDiagnosticsService class.

Here is the sample to write to the Trace Log:

SPDiagnosticsService diagSvc = SPDiagnosticsService.Local;
diagSvc.WriteTrace(0,
                   new SPDiagnosticsCategory("My Category",
                                             TraceSeverity.Monitorable,
                                             EventSeverity.Error),
                   TraceSeverity.Monitorable,
                   "An exception occurred: {0}",
                   new object[] {ex});

For every log record, ULS has “Area” and “Category”. By default, “Area” gets “Unknown” value.

Also, you may write directly to the Event Log:

SPDiagnosticsService diagSvc = SPDiagnosticsService.Local;
diagSvc.WriteEvent(0,
                   new SPDiagnosticsCategory("My Category",
                                             TraceSeverity.Monitorable,
                                             EventSeverity.Warning),
                   EventSeverity.Error,
                   "Exception occured {0}", new object[] {ex});

Suggestion #4 – Inherit SPDiagnosticsServiceBase to get more control over the logging process

If you are working on a big component or product, then it is reasonable to create your own “Diagnostics Service” – which is technically just a new class inherited from SPDiagnosticsServiceBase. You may define your own “Area” and “Category” as well as better methods to perform logging. Central Administration and PowerShell could also setup a different logging level per every “Category” or “Area”.

Here is a sample to start with:

public class LoggingService : SPDiagnosticsServiceBase
{
    public static string DiagnosticAreaName = "My";
    private static LoggingService _Current;
    public static LoggingService Current
    {
        get
        {
            if (_Current == null)
            {
               _Current = new LoggingService();
            }

            return _Current;
         }
    }

    private LoggingService(): base("My Logging Service", SPFarm.Local)
    {
    }

    protected override IEnumerable<SPDiagnosticsArea> ProvideAreas()
    {
        List<SPDiagnosticsArea> areas = new List<SPDiagnosticsArea>
        {
            new SPDiagnosticsArea(DiagnosticAreaName, new List<SPDiagnosticsCategory>
            {
                new SPDiagnosticsCategory("WebParts", 
                            TraceSeverity.Unexpected, EventSeverity.Error)
            })
        };
        return areas;
    }

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

Finally, the actual call could be like that:

LoggingService.LogError("WebParts", ex.ToString());

Suggestion #5 – Utilize diagnostics.asmx web service for the client side applications

It turns out that SharePoint has a /_vti_bin/diagnostics.asmx web service. It has only one method which performs log writing to the ULS with “SharePoint Foundation -> Unified Logging Service” category and “Verbose” level.

If you are crafting Silverlight or JavaScript application, then that web service could be the only way to perform logging which could be accessible by developers or administrators. Other options are quite hard to implement.

SharePoint has lots of Java Script libraries, and it also has functions such as ULSOnError(msg, url, line) and ULSSendException(ex). One does not simple call these functions, so you just need to include additional call ULS.enable with “true” value. Otherwise, you will not get anything at all.

ULS.enable = true;
ULSOnError("Hello trace", document.location.href, 0);

P.S. Do not forget that ULS was created for developers and administrators. You may consider creating something for the end users so SharePoint lists could be a nice option.

PPS. Well, actually there are six suggestions, but number 6 would just suck in the post title.