How to log exceptions

If you log exceptions by saving it’s message:

logger.Error("Operation failed." + ex.Message);

or it’s string representation:

logger.Error("Operation failed." + ex.ToString());

you do it wrong! It makes extremely hard if not impossible to find out what went wrong in the application.
To be able to successfully debug application from log files you have to log at least: exception type, message, stack trace and, recursively, inner exceptions. For more specific exceptions you also want to log their properties. And then there is an AggregateException for which you need to log all aggregated exceptions.

Logging frameworks

There are many logging frameworks available and you should definitely use one. Make sure that the framework will handle exception logging and than use it! Even if the framework allows for passing object to be logged, for exceptions you should use an overload method which takes exception as a parameter. Those methods will take care of saving at least most important details about the exception and usually will support saving properties of specific exceptions such as ErrorCode or Procedure from SqlException. You may also find that the framework takes special rendering class which allows for better control of rendered message.

log4net

The log4net is one of the frameworks I use and it has support for handling typical exceptions as well as for providing custom renderers. All logging methods have overload which takes an exception object as a parameter. You use it like that:

ILog logger;
[...]

try
{
    // code
}
catch (Exception ex)
{
    loger.Error("Failed to publish message to the bus.", ex);
    throw;
}

When the operation fails then you should have something like this in the log:

2014-05-09 15:56:45,180 [8] ERROR - Failed to publish message to the bus.
System.Exception: The operation failed.
   at Log4NetSpike.Program.TestException() in C:CodeCustom SolutionSpikesLog4NetSpikeLog4NetSpikeProgram.cs:line 43

If exception has InnerException than we get it’s details as well:

2014-05-09 16:03:10,968 [9] ERROR - Log exception
System.Exception: outer exception ---> System.Exception: The inner operation failed.
   at Log4NetSpike.Program.DoThrow() in C:CodeCustom SolutionSpikesLog4NetSpikeLog4NetSpikeProgram.cs:line 53
   at Log4NetSpike.Program.TestInnerException() in C:CodeCustom SolutionSpikesLog4NetSpikeLog4NetSpikeProgram.cs:line 62
   --- End of inner exception stack trace ---
   at Log4NetSpike.Program.TestInnerException() in C:CodeCustom SolutionSpikesLog4NetSpikeLog4NetSpikeProgram.cs:line 67

Using Exception Renderer

If you do not like the way the exception is rendered, or you want to log some custom exception properties then you can provide your own class which inherits from IObjectRenderer. Below is a sample renderer which logs detailed data fromSqlException:

To register the renderer add following line into your log4net configuration:

<renderer renderingClass="Log4NetSpike.SqlExceptionRenderer, Log4NetSpike" renderedClass="System.Data.SqlClient.SqlException, System.Data, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>

(set value of renderingClass to fully qualified name of the renderer you use.)

Debugging with logs

Now, once you have detailed information about the exception you can begin debugging. I usually start with checking the exception message and type. Next I use stack trace to find source code (if you use ReSharper than check out Browse Stack Trace from menu Tools) and by checking previous messages I try to determine what was going on in the app.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s