Single Responsibility Principle applied to exception logging

In the previous post How to log exceptions I said that you should let your logging framework handle exception logging. In this post I will explain why it is a bad idea to generate log messages in the catch block.

Lets first look at an example:

try
{
    UpdateAccount(userAccount);
}
catch (SqlException e)
{
    var sb = new StringBuilder();
    sb.AppendLine(e.ToString());
    sb.AppendFormat("Sql number: {0}", e.Number);
    sb.AppendFormat("Sql procedure: {0}", e.Procedure);
    sb.AppendFormat("Sql server: {0}", e.Server);

    logger.Error(sb.ToString());
}

As you can see, the main code invokes method UpdateAccount, which we can assume will perform update in the database. In the catch block error message is constructed with exception details and logged.

The first thing which you can easily notice is that exception handling block is much bigger than the main code. When analysing this code the user will have to filter out big chunk of exception formatting.

Next, because message formatting is embedded in the method, it will have to be duplicated across code base wherever SqlException is handled. The more places it is duplicated the harder it is to update.

And finally – it breaks Single Responsibility Principle. As defined by Uncle Bob:

A class should have one, and only one, reason to change.

In the above example, the class will have at least three reasons to change:

  1. the change in handling account update (this is the primary reason for this class)
  2. change in error message formatting, including adding/removing details
  3. change in error types handled, such as adding new error type to be logged

This is problematic because adding new exception property to be logged requires re-running all tests related to this call, including regression test. Suddenly a simple change is no longer simple.

The error message formatting logic belongs to the logging framework. Use type renderer for formatting message according to your needs. To handle logging new exception types you only need to create new type renderer and register it with logging framework. You can even reuse type renderers between different applications.
And the catch block will shrinks to one line of code:

logger.Error("Updating user account failed.", e);

Tell EasyNetQ bus what Queue name to use for your messages

When you consume messages from EasyNetQ bus you do not need to worry about naming and creating queues or exchanges. That’s done for you. The framework will use a pattern when generating name for the queue which is based on strongly typed name of the message type and consumer’s subscription id. Similar happens when generating exchange name. But is there anything you can do to change this behaviour?
Continue reading

EasyNetQ – methods for delivering messages

When designing your system you have few options on how the messages will be delivered to your consumers:

  1. messages are delivered in round-robin fashion – this is a great option for distributed, load balanced processing;
  2. messages are delivered to all consumers – this is the option to use if there are different processors for given message;
  3. hybrid solution where some consumers are getting messages in round robin fashion and other are getting all messages;

Round-robin delivery

In the round-robin delivery, the messages are automatically distributed between all consumers. By manipulating prefetchcount setting you can easily achieve load balancing. This scenario is great when there are many consumers doing the same type of processing. The example will be an order fulfilling system with few processors receiving orders. In the heavy load times you can spin extra consumers to cope with additional work, and the system will automatically deliver next message to free consumer using round-robin fashion.

When subscribing to the bus you have to specify the same subscriptionId for all consumers. You also need to set prefetchCount1 to small arbitrary value. This could be 1 or some other small value if buffering is necessary.

The above example shows 3 consumers subscribed to new order message. One of the consumers (no. 2) is processing messages slow, and due to load balancing will receive every 7th message (whenever it is ready to consume next message). Other consumers are processing messages with the same speed and are receiving them in round robin fashion.

All consumers delivery

This delivery mode will deliver every message to each subscribed consumer. This is useful in scenarios where there are many different processors interested in given message. For example, in the order fullfilment system, there may be one processor for verifying stock availability, another for billing and another for auditing and logging. When client places an order, new message is generated and copy of it is delivered to each processor. This allows for parallel processing, as each consumer may run on separate thread or machine. It also makes system open for extension – each new processor just registers interest in the message by subscribing to the bus.

When subscribing to the bus, each processor is using a different subscriptionId. When deciding on prefetchcount1 you may go with a higher value to get better performance.
As long as consumer code for each processor runs on different thread or different machine, the processing will be in parallel. Each consumer receives messages independently whenever it is ready.
The speed of processing messages by each processor doesn’t matter to other processors2. Messages are simply buffered in the queue.
Extending the system is simple. You create new consumer which subscribes to the bus with new subscriptionId and run it. During first run, EasyNetQ automatically creates and binds the queue, and messages get delivered to it.
When designing the system you can create conditional consumer. This kind of consumer will process messages only when some condition is met, such as: order value is over certain amount. When the condition isn’t met you return from the consuming method and the message is simply removed from the queue.

Hybrid solution

There is nothing to prevent you from using both delivery methods for the same message type. You can scale out each processor type by adding extra instances of it, so if you find for example that stock processor and billing processor are getting behind then scale those processors out.
If the system load varies than you can implement auto scaling – a system which will monitor queue sizes and automatically increase / decrease number of consumers to cope with the workload.



  1. prefetchcount is set when creating a bus. It’s value determines number of messages being cached by consumer for faster delivery. 
  2. There may be some performance hit with delivering a message when one queue gets big backlog of messages and RabbitMQ has to spend resources on persisting those. 

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.

Aside

Adding code block with markdown

I just learnt about using markdown and I love it! Now writing a post on my Surface RT is real pleasure. One thing I still am struggling with is to remember syntax for including a code block with formatting, which is:

  ```csharp
  Console.WriteLine("Hello World!");
  ```

for C#, and

  ```html
  <a href="http://www.mariuszwojcik.wordpress.com">My blog</a>
  ```

for HTML, and

   ```powershell
   Get-Service -ComputerName server RabbitMQ
   ```

for PowerShell.

Using complex type messages with EasyNetQ

This is the second post in series about EasyNetQ. In the first post I am explaining how to install RabbitMQ and write simple application which publishes and consumes string messages.

Complex type message

Usually you will need to send more complex types than string. Fortunately it is no harder than sending string messages. All you need to do is to create library project which will contain your message types and share it between publishers and consumers.

Load the example application you made in the first post and add new Class Library project to the solution named Messages. Add new class PersonName to that project which will represent persons name:

Next, add new class CreateAccountMessage to represent a message which is raised when user created new account:

Consuming complex type messages

There really is no difference in consuming complex type message from simple type message. All dirty work related to routing, serialisation and deserialisation is handled by EasyNetQ. All you have to do is to add reference to Messages project from your ConsumerApplication project and change Subscribe registration to

bus.Subscribe<CreateAccountMessage>("consumer1", message =>
    Console.WriteLine("Creating account for {0} {1}, age {2}.", message.Name.FirstName, message.Name.LastName, message.Age)
);

Publishing complex type messages

Again, as you would expect, nothing complicated here. Just add reference to Messages project from the PublisherApplication and change the call to Publish method to:

bus.Publish(new CreateAccountMessage("Joe", "Smith", 26));

Now run the ConsumerApplication by right clicking project name in Solution Explorer and selecting Debug > Start new instance. Next run the PublishedApplication project in the same way and you should see ConsumerApplication receiving the message.

Why do I have to share Messages

As you could see there is a need for sharing project with messages between publisher and consumer project. This is dictated by the way EasyNetQ is handling message delivery. Under the hood, the EasyNetQ is registering exchange and queue in RabbitMQ server using message strongly type names, which in our case will be Messages.CreateAccountMessage:Messages. If the consumer will subscribe to the bus with message type residing in different assembly (such as ConsumerApplication) then it won’t match the type of published message, even though they have the same definition.
Anyway, the requirement for sharing message types is not that bad as it will prevent problems with different versions of messages being published and consumed. It also allows for sharing message’s behaviour, as only data is carried over the message bus.

EasyNetQ with RabbitMQ – easy way to messaging

Few people have asked me already how to start using RabbitMQ in .NET, so I decided to write a short post about it.

Installation

First, visit erlang’s page, download erlang distribution according to your system (either 32 or 64 bit) and install it. If you have 64 bit machine (and you really should have) than get the 64 bit distribution, otherwise erlang process won’t be able to address more than 2GB of memory.

Next download RabbitMQ server and install it. I strongly recommend to install Management Plugin, which comes with RabbitMQ installation. All you need to do is run following command from command prompt (you may have to navigate to RabbitMQ’s sbin folder):

rabbitmq-plugins enable rabbitmq_management

There are detailed instructions on Management Plugin and its installation at http://www.rabbitmq.com/management.html.

Additionally, you may find useful RabbitMQTools – a power shell module for managing RabbitMQ servers.

EasyNetQ

Although pivotal provides a great .NET library for working with RabbitMQ, there is even better solution which will be sufficient in most cases – EasyNetQ. EasyNetQ provides nice abstraction over some low level concepts of RabbitMQ, such as topology registration, messages serialisation or error handling. It also gives an easy interface to work with some popular messaging patters such as Publish / Subscribe or Message Bus.

Hello World!

Lets create our first application. Start new console application project in Visual Studio and name it ConsumerApplication.
Add EasyNetQ nuget package:

Install-Package EasyNetQ

and replace Main.cs code with following:

Now, add new console application project to the solution and call it ProducerApplication. You also have to add EasyNetQ nuget package to this project.
Replace Main.cs code with following:

To run the example, first right click on the ConsumerApplication project and select Debug > Start new instance. This will run the ConsumerApplication. Next, do that same on the PublisherApplication and you should see that in the ConsumerApplication window there is a lot of diagnostics information printed and right at the bottom there is the Hello World! message.

How it works

Under the bonnet EasyNetQ is doing quite a work to make all this happen. When publishing the message, EasyNetQ performs a check to see whether the related Exchange exists in RabbitMQ and if it doesn’t than creates it. On the other hand, call to Subscribe method will verify whether both exchange and queue exists and they are bound together. As you can see in the console windows, EasyNetQ runs quite verbose diagnostics which are priceless when it comes to debugging. If there was a problem with consuming the message, such as exception thrown by consumer code, then it will be automatically moved to error queue for further analysis. You can also rely on EasyNetQ to manage connections to RabbitMQ server so you do not need to worry when the connection was dropped etc.

Summary

As you could see from the above example it is very easy to start with messaging using combination of RabbitMQ and EasyNetQ.
From serialising / de-serialising messages, diagnostics and error handling, managing connection to managing topology – all handled automatically by EasyNetQ so you can concentrate your efforts on making awesome applications. As you will see in the second article, working with complex type messages is no more complicated.