James Michael Hare

...hare-brained ideas from the realm of software development...
posts - 166 , comments - 1431 , trackbacks - 0

My Links

News

Welcome to my blog! I'm a Sr. Software Development Engineer in the Seattle area, who has been performing C++/C#/Java development for over 20 years, but have definitely learned that there is always more to learn!

All thoughts and opinions expressed in my blog and my comments are my own and do not represent the thoughts of my employer.

Blogs I Read

Follow BlkRabbitCoder on Twitter

Tag Cloud

Article Categories

Archives

.NET

CSharp

Little Wonders

Little Wonders

vNext

C#: Why Decorate When You Can Intercept

We've all heard of the old Decorator Design Pattern (here) or used it at one time or another either directly or indirectly.  A decorator is a class that wraps a given abstract class or interface and presents the same (or a superset) public interface but "decorated" with additional functionality.   As a really simplistic example, consider the System.IO.BufferedStream, it itself is a descendent of System.IO.Stream and wraps the given stream with buffering logic while still presenting System.IO.Stream's public interface:  

   1: Stream buffStream = new BufferedStream(rawStream);

Now, let's take a look at a custom-code example.  Let's say that we have a class in our data access layer that retrieves a list of products from a database: 

   1: // a class that handles our CRUD operations for products
   2: public class ProductDao
   3: {
   4:     ...
   5:  
   6:     // a method that would retrieve all available products
   7:     public IEnumerable<Product> GetAvailableProducts()
   8:     {
   9:         var results = new List<Product>();
  10:  
  11:         // must create the connection
  12:         using (var con = _factory.CreateConnection())
  13:         {
  14:             con.ConnectionString = _productsConnectionString;
  15:             con.Open();
  16:  
  17:             // create the command
  18:             using (var cmd = _factory.CreateCommand())
  19:             {
  20:                 cmd.Connection = con;
  21:                 cmd.CommandText = _getAllProductsStoredProc;
  22:                 cmd.CommandType = CommandType.StoredProcedure;
  23:  
  24:                 // get a reader and pass back all results
  25:                 using (var reader = cmd.ExecuteReader())
  26:                 {
  27:                     while(reader.Read())
  28:                     {
  29:                         results.Add(new Product
  30:                             {
  31:                                 Name = reader["product_name"].ToString(), 
  32:                                 ...
  33:                             });
  34:                     }
  35:                 }
  36:             }
  37:         }            
  38:  
  39:         return results;
  40:     }
  41: }

Yes, you could use EF or any myriad other choices for this sort of thing, but the germaine point is that you have some operation that takes a non-trivial amount of time.  What if, during the production day I notice that my application is performing slowly and I want to see how much of that slowness is in the query versus my code.  Well, I could easily wrap the logic block in a System.Diagnostics.Stopwatch and log the results to log4net or other logging flavor of choice:

   1:     // a class that handles our CRUD operations for products
   2:     public class ProductDao
   3:     {
   4:         private static readonly ILog _log = LogManager.GetLogger(typeof(ProductDao));
   5:         ...
   6:         
   7:         // a method that would retrieve all available products
   8:         public IEnumerable<Product> GetAvailableProducts()
   9:         {
  10:             var results = new List<Product>();
  11:             var timer = Stopwatch.StartNew();
  12:             
  13:             // must create the connection
  14:             using (var con = _factory.CreateConnection())
  15:             {
  16:                 con.ConnectionString = _productsConnectionString;
  17:                 
  18:                 // and all that other DB code...
  19:                 ...
  20:             }
  21:             
  22:             timer.Stop();
  23:             
  24:             if (timer.ElapsedMilliseconds > 5000)
  25:             {
  26:                 _log.WarnFormat("Long query in GetAvailableProducts() took {0} ms",
  27:                     timer.ElapsedMillseconds);
  28:             }
  29:             
  30:             return results;
  31:         }
  32:     }

In my eye, this is very ugly.  It violates Single Responsibility Principle (SRP), which says that a class should only ever have one responsibility, where responsibility is often defined as a reason to change. 
This class (and in particular this method) has two reasons to change:

  • If the method of retrieving products changes.
  • If the method of logging changes.

Well, we could “simplify” this using the Decorator Design Pattern (here).  If we followed the pattern to the letter, we'd need to create a base decorator that implements the DAOs public interface and forwards to the wrapped instance.  So let's assume we break out the ProductDAO interface into IProductDAO using your refactoring tool of choice (Resharper is great for this).

Now, ProductDao will implement IProductDao and get rid of all logging logic:

   1:     public class ProductDao : IProductDao
   2:     {
   3:         // this reverts back to original version except for the interface added
   4:     }
   5:  

And we create the base Decorator that also implements the interface and forwards all calls:

   1:     public class ProductDaoDecorator : IProductDao
   2:     {
   3:         private readonly IProductDao _wrappedDao;
   4:         
   5:         // constructor takes the dao to wrap
   6:         public ProductDaoDecorator(IProductDao wrappedDao)
   7:         {
   8:             _wrappedDao = wrappedDao;
   9:         }
  10:         
  11:         ...
  12:         
  13:         // and then all methods just forward their calls
  14:         public IEnumerable<Product> GetAvailableProducts()
  15:         {
  16:             return _wrappedDao.GetAvailableProducts();
  17:         }
  18:     }

This defines our base decorator, then we can create decorators that add items of interest, and for any methods we don't decorate, we'll get the default behavior which just forwards the call to the wrapper in the base decorator:

   1:     public class TimedThresholdProductDaoDecorator : ProductDaoDecorator
   2:     {
   3:         private static readonly ILog _log = LogManager.GetLogger(typeof(TimedThresholdProductDaoDecorator));
   4:         
   5:         public TimedThresholdProductDaoDecorator(IProductDao wrappedDao) :
   6:             base(wrappedDao)
   7:         {
   8:         }
   9:         
  10:         ...
  11:         
  12:         public IEnumerable<Product> GetAvailableProducts()
  13:         {
  14:             var timer = Stopwatch.StartNew();
  15:             
  16:             var results = _wrapped.GetAvailableProducts();
  17:             
  18:             timer.Stop();
  19:             
  20:             if (timer.ElapsedMilliseconds > 5000)
  21:             {
  22:                 _log.WarnFormat("Long query in GetAvailableProducts() took {0} ms",
  23:                     timer.ElapsedMillseconds);
  24:             }
  25:             
  26:             return results;
  27:         }
  28:     }

Well, it's a bit better.  Now the logging is in its own class, and the database logic is in its own class.  But we've essentially multiplied the number of classes.  We now have 3 classes and one interface!  Now if you want to do that same logging decorating on all your DAOs, imagine the code bloat!  Sure, you can simplify and avoid creating the base decorator, or chuck it all and just inherit directly.  But regardless all of these have the problem of tying the logging logic into the code itself.

Enter the Interceptors.  Things like this to me are a perfect example of when it's good to write an Interceptor using your class library of choice.  Sure, you could design your own perfectly generic decorator with delegates and all that, but personally I'm a big fan of Castle's Dynamic Proxy (here) which is actually used by many projects including Moq.

What DynamicProxy allows you to do is intercept calls into any object by wrapping it with a proxy on the fly that intercepts the method and allows you to add functionality.  Essentially, the code would now look like this using DynamicProxy:

   1: // Note: I like hiding DynamicProxy behind the scenes so users
   2: // don't have to explicitly add reference to Castle's libraries.
   3: public static class TimeThresholdInterceptor 
   4: {
   5:     // Our logging handle
   6:     private static readonly ILog _log = LogManager.GetLogger(typeof(TimeThresholdInterceptor));
   7:  
   8:     // Handle to Castle's proxy generator
   9:     private static readonly ProxyGenerator _generator = new ProxyGenerator();
  10:  
  11:     // generic form for those who prefer it
  12:     public static object Create<TInterface>(object target, TimeSpan threshold)
  13:     {
  14:         return Create(typeof(TInterface), target, threshold);
  15:     }
  16:  
  17:     // Form that uses type instead
  18:     public static object Create(Type interfaceType, object target, TimeSpan threshold)
  19:     {
  20:         return _generator.CreateInterfaceProxyWithTarget(interfaceType, target,
  21:              new TimedThreshold(threshold, level));
  22:     }
  23:  
  24:     // The interceptor that is created to intercept the interface calls.
  25:     // Hidden as a private inner class so not exposing Castle libraries.
  26:     private class TimedThreshold : IInterceptor
  27:     {
  28:         // The threshold as a positive timespan that triggers a log message.
  29:         private readonly TimeSpan _threshold;
  30:  
  31:         // interceptor constructor
  32:         public TimedThreshold(TimeSpan threshold)
  33:         {
  34:             _threshold = threshold;
  35:         }
  36:  
  37:         // Intercept functor for each method invokation
  38:         public void Intercept(IInvocation invocation)
  39:         {
  40:             // time the method invocation
  41:             var timer = Stopwatch.StartNew();
  42:  
  43:             // the Castle magic that tells the method to go ahead
  44:             invocation.Proceed();
  45:  
  46:             timer.Stop();
  47:  
  48:             // check if threshold is exceeded
  49:             if (timer.Elapsed > _threshold)
  50:             {
  51:                 _log.WarnFormat("Long execution in {0} took {1} ms",
  52:                         invocation.Method.Name,
  53:                         timer.ElapsedMillseconds);
  54:             }
  55:         }
  56:     }
  57: }

Yes, it's a bit longer, but notice that:

  • This class ONLY deals with logging long method calls, no DAO interface leftovers.
  • This class can be used to time ANY class that has an interface or virtual methods.

Personally, I like to wrap and hide the usage of DynamicProxy and IInterceptor so that anyone who uses this class doesn't need to know to add a Castle library reference.  As far as they are concerned, they're using my interceptor.  If I change to a new library if a better one comes along, they're insulated.

Now, all we have to do to use this is to tell it to wrap our ProductDao and it does the rest:

   1: // wraps a new ProductDao with a timing interceptor with a threshold of 5 seconds
   2: IProductDao dao = TimeThresholdInterceptor.Create<IProductDao>(new ProductDao(), 5000);

Automatic decoration of all methods!  You can even refine the proxy so that it only intercepts certain methods.
This is ideal for so many things.  These are just some of the interceptors we've dreamed up and use:

  • Log parameters and returns of methods to XML for auditing.
  • Block invocations to methods and return default value (stubbing).
  • Throw exception if certain methods are called (good for blocking access to deprecated methods).
  • Log entrance and exit of a method and the duration.
  • Log a message if a method takes more than a given time threshold to execute.

Whether you use DynamicProxy or some other technology, I hope you see the benefits this adds.  Does it completely eliminate all need for the Decorator pattern?  No, there may still be cases where you want to decorate a particular class with functionality that doesn't apply to the world at large.

But for all those cases where you are using Decorator to add functionality that's truly generic.  I strongly suggest you give this a try!

Print | posted on Thursday, May 6, 2010 7:01 PM | Filed Under [ My Blog C# ]

Powered by: