次の方法で共有


Logging Exceptions in .NET Applications

Last summer I wrote a post introducing my simple, but highly effective approach to logging -- including a Logger class that is really just a thin wrapper around the System.Diagnostics.TraceSource class.

A few months ago, I enhanced the Logger class to log exceptions in a consistent fashion.

I used the "Yellow Page of Death" provided by ASP.NET as a reference for logging the details of the exception. Here's a screenshot from a sample that I whipped up this morning:

Figure 1: ASP.NET error page

See full-sized image.

The corresponding code-behind from the page that I used to generate the above screenshot is listed below:

 using System;

using Fabrikam.Demo.CoreServices.Logging;

namespace Fabrikam.Demo.Web.UI.Logging
{
    public partial class UnhandledExceptionPage : System.Web.UI.Page
    {
        protected void Page_Load(
            object sender,
            EventArgs e)
        {
            DoSomethingBad();
        }

        [System.Diagnostics.CodeAnalysis.SuppressMessage(
            "Microsoft.Performance",
            "CA1804:RemoveUnusedLocals",
            MessageId = "divideByZero")]
        private static void DoSomethingBad()
        {
            int numerator = 1;
            int denominator = 0;

            try
            {
                int divideByZero = numerator / denominator;
            }
            catch (DivideByZeroException ex)
            {
                string errorMessage = "Something bad happened.";
                Logger.LogError(errorMessage);

                throw new InvalidOperationException(
                    errorMessage,
                    ex);
            }
        }
    }
}

A couple of interesting notes about the ASP.NET error page:

  • The error message displayed at the top of the page is actually from the innermost exception (i.e. the "base" exception).
  • The stack trace shows the details for the actual exception that occurred as well as any inner exceptions.

This makes perfect sense when you think about it because when you start investigating an error, it's best to begin with the crux of the problem. In other words, for this example, it's much better start off with the "Attempted to divide by zero" message from the DivideByZeroException, rather than the "Something bad happened" message from the InvalidOperationExeption.

In order to log exceptions, I added two new overloads for the LogError method:

         /// <summary>
        /// Logs the specified exception to the trace listeners.
        /// </summary>
        /// <param name="ex">The exception to log.</param>
        public static void LogError(
            Exception ex)
        {
            LogError(ex, null);
        }

        /// <summary>
        /// Logs the specified exception to the trace listeners.
        /// </summary>
        /// <remarks>The details of the exception are logged using a format
        /// similar to the ASP.NET error page. Information about the base
        /// exception is logged first, followed by information for any
        /// "outer" exceptions.</remarks>
        /// <param name="ex">The exception to log.</param>
        /// <param name="requestUrl">The URL of the web request for which the
        /// exception occurred.</param>
        public static void LogError(
            Exception ex,
            Uri requestUrl)
        {
            if (ex == null)
            {
                throw new ArgumentNullException("ex");
            }

            StringBuilder buffer = new StringBuilder();

            if (requestUrl == null)
            {
                buffer.Append(
                    "An error occurred in the application.");
            }
            else
            {
                buffer.Append(
                    "An error occurred during the execution of the"
                    + " web request.");
            }

            buffer.Append(
                " Please review the stack trace for more information about the"
                + " error and where it originated in the code.");

            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            if (requestUrl != null)
            {
                buffer.Append("Request URL: ");
                buffer.Append(requestUrl.AbsoluteUri);

                buffer.Append(Environment.NewLine);
                buffer.Append(Environment.NewLine);
            }

            Exception baseException = ex.GetBaseException();
            Type baseExceptionType = baseException.GetType();

            buffer.Append("Exception Details: ");
            buffer.Append(baseExceptionType.FullName);
            buffer.Append(": ");
            buffer.Append(baseException.Message);

            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            buffer.Append("Stack Trace:");
            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            AppendExceptionDetail(ex, buffer);

            string message = buffer.ToString();
            Log(TraceEventType.Error, message);
        }

Note that the stack trace is generated using the AppendExceptionDetail helper method.

This makes it really easy to log exceptions in ASP.NET Web applications -- including solutions built on Microsoft Office SharePoint Server (MOSS) 2007 and Windows SharePoint Services -- as well as other types of .NET applications (e.g. console applications).

Here is the complete source for the updated Logger class:

 #define TRACE

using System;
using System.Diagnostics;
using System.Globalization;
using System.Text;

namespace Fabrikam.Demo.CoreServices.Logging
{
    /// <summary>
    /// Exposes static methods for logging various events (e.g. debug,
    /// informational, warning, etc.). This class cannot be inherited.
    /// </summary>
    /// <remarks>
    /// All methods of the <b>Logger</b> class are static
    /// and can therefore be called without creating an instance of the class.
    /// </remarks>
    public static class Logger
    {
        private static TraceSource defaultTraceSource =
            new TraceSource("defaultTraceSource");

        private static void AppendExceptionDetail(
            Exception ex,
            StringBuilder buffer)
        {
            Debug.Assert(ex != null);
            Debug.Assert(buffer != null);

            if (ex.InnerException != null)
            {
                AppendExceptionDetail(ex.InnerException, buffer);
            }

            Type exceptionType = ex.GetType();

            buffer.Append('[');
            buffer.Append(exceptionType.Name);
            buffer.Append(": ");
            buffer.Append(ex.Message);
            buffer.Append(']');
            buffer.Append(Environment.NewLine);

            // Note: Exception.StackTrace includes both _stackTrace and
            // _remoteStackTrace, so use System.Diagnostics.StackTrace
            // to retrieve only the portion we want to output
            StackTrace trace = new StackTrace(ex);
            buffer.Append(trace.ToString());

            buffer.Append(Environment.NewLine);
        }

        /// <summary>
        /// Flushes all the trace listeners in the trace listener collection.
        /// </summary>
        public static void Flush()
        {
            defaultTraceSource.Flush();
        }

        /// <summary>
        /// Logs an event to the trace listeners using the specified
        /// event type and message.
        /// </summary>
        /// <param name="eventType">One of the System.Diagnostics.TraceEventType
        /// values that specifies the type of event being logged.</param>
        /// <param name="message">The message to log.</param>
        public static void Log(
            TraceEventType eventType,
            string message)
        {
#if DEBUG
            // Some debug listeners (e.g. DbgView.exe) don't buffer output, so
            // Debug.Write() is effectively the same as Debug.WriteLine().
            // For optimal appearance in these listeners, format the output
            // for a single call to Debug.WriteLine().
            StringBuilder sb = new StringBuilder();

            sb.Append(eventType.ToString());
            sb.Append(": ");
            sb.Append(message);

            string formattedMessage = sb.ToString();
            Debug.WriteLine(formattedMessage);
#endif

            defaultTraceSource.TraceEvent(eventType, 0, message);
        }

        /// <summary>
        /// Logs a debug event to the trace listeners using the specified
        /// format string and arguments.
        /// </summary>
        /// <param name="provider">An System.IFormatProvider that supplies
        /// culture-specific formatting information.</param>
        /// <param name="format">A composite format string.</param>
        /// <param name="args">An System.Object array containing zero or more
        /// objects to format.</param>
        public static void LogDebug(
            IFormatProvider provider,
            string format,
            params object[] args)
        {
            string message = string.Format(
                provider, format, args);

            LogDebug(message);
        }

        /// <summary>
        /// Logs a debug event to the trace listeners.
        /// </summary>
        /// <param name="message">The message to log.</param>
        public static void LogDebug(
            string message)
        {
            Log(TraceEventType.Verbose, message);
        }

        /// <summary>
        /// Logs a critical event to the trace listeners using the specified
        /// format string and arguments.
        /// </summary>
        /// <param name="provider">An System.IFormatProvider that supplies
        /// culture-specific formatting information.</param>
        /// <param name="format">A composite format string.</param>
        /// <param name="args">An System.Object array containing zero or more
        /// objects to format.</param>
        public static void LogCritical(
            IFormatProvider provider,
            string format,
            params object[] args)
        {
            string message = string.Format(
                provider, format, args);

            LogCritical(message);
        }

        /// <summary>
        /// Logs a critical event to the trace listeners.
        /// </summary>
        /// <param name="message">The message to log.</param>
        public static void LogCritical(
            string message)
        {
            Log(TraceEventType.Critical, message);
        }

        /// <summary>
        /// Logs an error event to the trace listeners using the specified
        /// format string and arguments.
        /// </summary>
        /// <param name="provider">An System.IFormatProvider that supplies
        /// culture-specific formatting information.</param>
        /// <param name="format">A composite format string.</param>
        /// <param name="args">An System.Object array containing zero or more
        /// objects to format.</param>
        public static void LogError(
            IFormatProvider provider,
            string format,
            params object[] args)
        {
            string message = string.Format(
                provider, format, args);

            LogError(message);
        }

        /// <summary>
        /// Logs the specified exception to the trace listeners.
        /// </summary>
        /// <param name="ex">The exception to log.</param>
        public static void LogError(
            Exception ex)
        {
            LogError(ex, null);
        }

        /// <summary>
        /// Logs the specified exception to the trace listeners.
        /// </summary>
        /// <remarks>The details of the exception are logged using a format
        /// similar to the ASP.NET error page. Information about the base
        /// exception is logged first, followed by information for any
        /// "outer" exceptions.</remarks>
        /// <param name="ex">The exception to log.</param>
        /// <param name="requestUrl">The URL of the web request for which the
        /// exception occurred.</param>
        public static void LogError(
            Exception ex,
            Uri requestUrl)
        {
            if (ex == null)
            {
                throw new ArgumentNullException("ex");
            }

            StringBuilder buffer = new StringBuilder();

            if (requestUrl == null)
            {
                buffer.Append(
                    "An error occurred in the application.");
            }
            else
            {
                buffer.Append(
                    "An error occurred during the execution of the"
                    + " web request.");
            }

            buffer.Append(
                " Please review the stack trace for more information about the"
                + " error and where it originated in the code.");

            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            if (requestUrl != null)
            {
                buffer.Append("Request URL: ");
                buffer.Append(requestUrl.AbsoluteUri);

                buffer.Append(Environment.NewLine);
                buffer.Append(Environment.NewLine);
            }

            Exception baseException = ex.GetBaseException();
            Type baseExceptionType = baseException.GetType();

            buffer.Append("Exception Details: ");
            buffer.Append(baseExceptionType.FullName);
            buffer.Append(": ");
            buffer.Append(baseException.Message);

            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            buffer.Append("Stack Trace:");
            buffer.Append(Environment.NewLine);
            buffer.Append(Environment.NewLine);

            AppendExceptionDetail(ex, buffer);

            string message = buffer.ToString();
            Log(TraceEventType.Error, message);
        }

        /// <summary>
        /// Logs an error event to the trace listeners.
        /// </summary>
        /// <param name="message">The message to log.</param>
        public static void LogError(
            string message)
        {
            Log(TraceEventType.Error, message);
        }

        /// <summary>
        /// Logs an informational event to the trace listeners using the specified
        /// format string and arguments.
        /// </summary>
        /// <param name="provider">An System.IFormatProvider that supplies
        /// culture-specific formatting information.</param>
        /// <param name="format">A composite format string.</param>
        /// <param name="args">An System.Object array containing zero or more
        /// objects to format.</param>
        public static void LogInfo(
            IFormatProvider provider,
            string format,
            params object[] args)
        {
            string message = string.Format(
                provider, format, args);

            LogInfo(message);
        }

        /// <summary>
        /// Logs an informational event to the trace listeners.
        /// </summary>
        /// <param name="message">The message to log.</param>
        public static void LogInfo(
            string message)
        {
            Log(TraceEventType.Information, message);
        }

        /// <summary>
        /// Logs a warning event to the trace listeners using the specified
        /// format string and arguments.
        /// </summary>
        /// <param name="provider">An System.IFormatProvider that supplies
        /// culture-specific formatting information.</param>
        /// <param name="format">A composite format string.</param>
        /// <param name="args">An System.Object array containing zero or more
        /// objects to format.</param>
        public static void LogWarning(
            IFormatProvider provider,
            string format,
            params object[] args)
        {
            string message = string.Format(
                provider, format, args);

            LogWarning(message);
        }

        /// <summary>
        /// Logs a warning event to the trace listeners.
        /// </summary>
        /// <param name="message">The message to log.</param>
        public static void LogWarning(
            string message)
        {
            Log(TraceEventType.Warning, message);
        }
    }
}

In a follow-up post, I'll cover how to handle errors in SharePoint Web applications without necessarily adding a bunch or try/catch blocks, while still avoiding the out-of-the-box SharePoint error page (which doesn't look very good on an Internet-facing site).

Update (2011-01-31)

I've attached a sample Visual Studio solution that demonstrates the Logger class.

Demo (LoggingAndDiagnostics).zip

Comments

  • Anonymous
    March 20, 2010
    Hey Jeremy, Great Post. I believe proper exception handling and logging is the most obscure and unmastered subject for beginners to intermediate developers. At least that's the impression I get from interviews I conduct.

  • Anonymous
    March 21, 2010
    Why not use the Enterprise Library instead?

  • Anonymous
    March 21, 2010
    Why not just use Elmah or log4net?

  • Anonymous
    March 21, 2010
    I haven't used Enterprise Library in years. You are certainly welcome to use it instead, but I find the System.Diagnostics stuff introduced in .NET 2.0 to be much easier to implement on a project. [My general opinion about the Enterprise Library is certainly much stronger than what I've briefly mentiond here, but I'll leave it at that ;-) ] As for log4net -- honestly, I never used this on any projects primarily because of "open source" and supportability issues (at Microsoft Consulting Services, we have to jump through some hoops in order to use any third party code on customer projects that we lead). One of the customers that I worked with years ago actually used log4net prior to engaging with MCS, but having already implemented it in their solution mitigated the supportability and open source issues. I looked ever so briefly at ELMAH about a year ago (if memory serves) shortly after it was mentioned on Scott Hanselman's blog, but again, I've never used it "in the real world" on a project that I've been involved with. Has anyone used it in conjunction with SharePoint? That would be my primary concern (i.e. it either doesn't work or isn't supported when used on a SharePoint site). There's also the issue of supportability with ELMAH as well (since I believe it's also an open source project).

  • Anonymous
    March 22, 2010
    Jeremy, since log4net is OSS, you can support it and "claim it" as your own.  It is not 3rd party software, which i can definitely understand getting permission for, especially since you don't have the source. It is much better than just rolling your own. But rules are rules. Silly and short-sighted as they might be.

  • Anonymous
    March 23, 2010
    The comment has been removed

  • Anonymous
    March 14, 2011
    The comment has been removed

  • Anonymous
    March 14, 2011
    The comment has been removed