A Cowboy, a decorator and an interceptor does some logging
Imagine that we have a service that’s responsible for fetching some pagedata. The following interface and class is used
1: public interface IPageLoadService
2: {
3: PageData Load(int id);
4: }
1: public class PageLoadService : IPageLoadService
2: {
3: public PageData Load(int id)
4: {
5: System.Threading.Thread.Sleep(2000);
6: var pageData = new PageData();
7: return pageData;
8: }
9:
10: }
Now, for some reason your code seems slow and you have a feeling that it might be your PageLoadService that’s the cause. Since it’s always a wise idea to actually measure this instead of guestimate where performance bottlenecks are you decide to add a simple stop watch to track the time the method takes.
(Nitpick corner. No, I don’t suggest using Response.Write “logging”. This was just quick to do to get the point about the various ways to do the logging across.)
One, the cowboy way
1: public class PageLoadService : IPageLoadService
2: {
3: public PageData Load(int id)
4: {
5: Stopwatch watch = new Stopwatch();
6: watch.Start();
7:
8: System.Threading.Thread.Sleep(2000);
9: var pageData = new PageData();
10:
11: watch.Stop();
12: HttpContext.Current.Response.Write("Time elapsed: " + watch.ElapsedMilliseconds);
13:
14: return pageData;
15: }
16: }
1: Virtual.PageLoadService service = new PageLoadService();
2: service.Load(5);
Now, if you’ve read any of my other posts on design and testing you can probably tell that this code won’t make the S in Solid very happy since it’s now responsible for both fetching page data and some sort of logging. It can also be cumbersome to maintain since you have to edit this code if you want to activate / deactivate the logging.
Two, using a decorator
We revert the PageLoadService back to it’s original state since it won’t handle the logging anymore. That will be handled by a decorator that simply adds the logging and then calls the original service to perform the actual fetching of the page data.
We start with an abstract base decorator
1: public abstract class PageLoadServiceDecorator : IPageLoadService
2: {
3: protected IPageLoadService WrappedPageLoadService;
4:
5: public PageLoadServiceDecorator(IPageLoadService wrappedPageLoadService)
6: {
7: this.WrappedPageLoadService = wrappedPageLoadService;
8: }
9:
10: public virtual PageData Load(int id)
11: {
12: return WrappedPageLoadService.Load(id);
13: }
14: }
and then create a concrete implementation for our stop watch logging.
1: public class PageLoadServiceStopWatchDecorator : PageLoadServiceDecorator
2: {
3: public PageLoadServiceStopWatchDecorator(IPageLoadService wrappedPageLoadService)
4: : base(wrappedPageLoadService)
5: {
6: }
7:
8: public override PageData Load(int id)
9: {
10: Stopwatch watch = new Stopwatch();
11: watch.Start();
12:
13: var pageData = base.WrappedPageLoadService.Load(id);
14:
15: watch.Stop();
16: HttpContext.Current.Response.Write("Time elapsed: " + watch.ElapsedMilliseconds);
17: return pageData;
18: }
19: }
We simply new up the decorator scenario we’d like. In our case we only have one so the initiation looks like this
1: var service2 = new PageLoadServiceStopWatchDecorator(new PageLoadService());
2: service2.Load(5);
Three, using an interceptor
In my previous post about why you have to mark you properties as virtual when using PTB I talked a bit about interceptors and dynamic proxies. What we basically want here is to run some code before and after the actual call to the page data loading service. As such, using a interceptor would solve this problem quite nicely.
We start with a class that build the proxy for us.
1: public class InterceptorBuilder
2: {
3: private static readonly ProxyGenerator Generator = new ProxyGenerator();
4:
5: public static TInterface Create<TInterface>(object target, IInterceptor interceptor) where TInterface : class
6: {
7: return Generator.CreateInterfaceProxyWithTarget(typeof(TInterface), target, interceptor) as TInterface;
8: }
9: }
The generic Create method simply takes a target (which is the class to intercept) and the class with which to intercept it with.
1: public class StopWatchInterceptor : IInterceptor
2: {
3: public void Intercept(IInvocation invocation)
4: {
5: Stopwatch watch = new Stopwatch();
6: watch.Start();
7:
8: invocation.Proceed();
9:
10: watch.Stop();
11: HttpContext.Current.Response.Write("Time elapsed: " + watch.ElapsedMilliseconds);
12: }
13: }
The class that does the interception has to implement the IInterceptor interface.
1: public class StopWatchInterceptor : IInterceptor
2: {
3: public void Intercept(IInvocation invocation)
4: {
5: Stopwatch watch = new Stopwatch();
6: watch.Start();
7:
8: invocation.Proceed();
9:
10: watch.Stop();
11: HttpContext.Current.Response.Write("Time elapsed: " + watch.ElapsedMilliseconds);
12: }
13: }
This method is called when a suitable method to intercept (in our case it’s every method) is called. We can then do whatever we please before telling the method to go ahead and execute. This is done on line 8 with the call to the Proceed method.
To use this we simply call the static Create method on our InterceptorBuilder.
1: var service3 = InterceptorBuilder.Create<IPageLoadService>(new PageLoadService(), new StopWatchInterceptor());
2: service3.Load(5);
Note that our interceptor can basically intercept any class that implements an interface so if we wanted to implement logging on another class it would be as simple as changing the initializing.
1: var service3 = InterceptorBuilder.Create<ISomeOtherService>(new SomeOtherService(), new StopWatchInterceptor());
2: service3.Do1();
3: service3.Do2();
This would perform the stopwatch logic for both Do1 and Do2.
This is of course not always what you want and not something I’d generally recommend. Often you’d want to specify which members of your class that you’d want to be intercepted. There’s a lot more to be said about the DynamicProxy framework but hopefully this short post at least somewhat inspired you.
Comments