How to use log every call of your WCF service's methods

Posted on: 2013-04-09

If you want to log information like which method has been called with which parameters on every methods of your WCF service, you shouldn't set the log every time on each method. Two approaches is possible to create something clean.

The first option is to create an attribute and when this one is present will log. The second is to automatically log every call. I'll show you the second approach since it's seem more logic to log every methods. If you are curious about how to do it with an attribute, I'll post in few times the code to apply security with WCF with attribute which will show you how to do it.

This article shows you how to log every calls of WCF's methods. It will use Unity as IOC. So, this article show you how to use an IOC (Unity) with WCF also.

The first step is to modify your service definition. This can be done by editing the .scv (not the .svc.cs).

<%@ ServiceHost Language="C#" Debug="true" Service="MyNameSpace.MyServices.MyService" CodeBehind="MyService.svc.cs" Factory="MyNameSpace.MyServices.Common.MyServiceHostFactory " %> 

The important modification is the Factory attribute. This one is required to be able to use Unity. This act as the global.asax.cs. By this, I mean, it's called when the service is initialized and not at every calls. Behind this factory, you own class is instanced and you are able to return your own ServiceHost class. This is a door to initialize Unity (IoC), AutoMapper and many others utilities class that need to be instanced once.

public class MyServiceHostFactory : ServiceHostFactory { 
  protected override ServiceHost CreateServiceHost(Type serviceType, Uri[] baseAddresses) {
    var serviceHost = new MyServiceHost(serviceType, baseAddresses); 
    //ConfigureUnity(serviceHost.Container); 
    //ConfigureAutoMapper();
    return serviceHost; 
  } 
} 

The MyServiceHostFactory creates a MyServiceHost and configure the inversion of control container. It also initialize the Automapper configuration. The MyServiceHost inherit from ServiceHost, which let you add the implementation of the IoC container and handle behaviors. To be able to log on every service's method, a new behavior need to be defined.

public class MyServiceHost : ServiceHost { 
  public UnityContainer Container { get; set; } 
  public MyServiceHost() { Container = new UnityContainer(); }

  public MyServiceHost(Type serviceType, params Uri[] baseAddresses): base(serviceType, baseAddresses) { 
    Container = new UnityContainer();
  }

  protected override void OnOpening() { 
    base.OnOpening();

    if (this.Description.Behaviors.Find<MyServiceBehavior>() == null) { 
      this.Description.Behaviors.Add(new MyServiceBehavior(Container)); 
    } 
  } 
} 

The MyServiceHost initializes the container and add a single behavior which handle the logging feature.

public class MyServiceBehavior : IServiceBehavior { 
  public UnityInstanceProvider InstanceProvider { get; set; }

  public MyServiceBehavior() { InstanceProvider = new UnityInstanceProvider(); }

  public MyServiceBehavior(UnityContainer unity) { InstanceProvider = new UnityInstanceProvider {Container = unity}; }

  public void AddBindingParameters(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase, Collection<ServiceEndpoint> endpoints, BindingParameterCollection bindingParameters) { }

  public void ApplyDispatchBehavior(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase) { 
    InstanceProvider.ServiceType = serviceDescription.ServiceType; 
    foreach (ChannelDispatcherBase cdb in serviceHostBase.ChannelDispatchers) { 
      var cd = cdb as ChannelDispatcher; if (cd != null) { 
        foreach (EndpointDispatcher ed in cd.Endpoints) { 
          ed.DispatchRuntime.InstanceProvider = InstanceProvider; 
        } 
      } 
    }

    var log = InstanceProvider.Container.Resolve<ILog>(); 
    IOperationBehavior behavior = new LoggingOperationBehavior(log); 
    foreach (ServiceEndpoint endpoint in serviceDescription.Endpoints) { 
      foreach (OperationDescription operation in endpoint.Contract.Operations) { 
        if (!operation.Behaviors.Any(d => d is LoggingOperationBehavior)) { 
          operation.Behaviors.Add(behavior); 
        } 
      } 
    } 
  }

  public void Validate(ServiceDescription serviceDescription, ServiceHostBase serviceHostBase) { } 
} 

This is where we attach for all endpoints, all operations (methods) the behavior to be executed. This is where we add the logging behavior. The first foreach is required for Unity to be the provider while the second foreach is there to add the logging behavior.

public class UnityInstanceProvider : IInstanceProvider { 
  public IUnityContainer Container { set; get; } 
  public Type ServiceType { set; get; }

  public UnityInstanceProvider() : this(null) { }

  public UnityInstanceProvider(Type type) { ServiceType = type; Container = new UnityContainer(); }

  public object GetInstance(InstanceContext instanceContext, Message message) { return Container.Resolve(ServiceType); }

  public object GetInstance(System.ServiceModel.InstanceContext instanceContext) { return GetInstance(instanceContext, null); }

  public void ReleaseInstance(InstanceContext instanceContext, object instance) {

    var myInstance = instance as IDisposable;

    if (myInstance != null) { 
      myInstance.Dispose(); 
    } 
  } 
} 

public class LoggingOperationBehavior : IOperationBehavior { 
  private readonly ILog_myLog;

  public LoggingOperationBehavior(ILog myLog) {_myLog = myLog; }

  public void ApplyDispatchBehavior(OperationDescription operationDescription, DispatchOperation dispatchOperation) { 
    dispatchOperation.Invoker = new LoggingOperationInvoker(_myLog, dispatchOperation.Invoker, dispatchOperation); 
  } 
  
  public void Validate(OperationDescription operationDescription) { } 
  
  public void ApplyClientBehavior(OperationDescription operationDescription, ClientOperation clientOperation) { }

  public void AddBindingParameters(OperationDescription operationDescription, BindingParameterCollection bindingParameters) { }
} 

At this point, we need to invoke the log. We need to specify an invoker that will be executed. This is why, we need to create a logging invoker which take the log that come from Unity.

public class LoggingOperationInvoker : IOperationInvoker { 
  private readonly IOperationInvoker_baseInvoker; 
  private readonly string_operationName; 
  private readonly string_controllerName; 
  private readonly ILog_myLog;

  public LoggingOperationInvoker(ILog myLog, IOperationInvoker baseInvoker, DispatchOperation operation) {
    _myLog = myLog;_baseInvoker = baseInvoker;
    _operationName = operation.Name;
    _controllerName = operation.Parent.Type==null?"[None]":operation.Parent.Type.FullName; 
  } 
  
  public object Invoke(object instance, object[] inputs, out object[] outputs) {
    _myLog.Log("Method " +_operationName + " of class " +_controllerName + " called"); 
    try { return_baseInvoker.Invoke(instance, inputs, out outputs); } 
    catch (Exception ex) {_myLog.Log(ex); throw; } 
  }

  public object[] AllocateInputs() {return_baseInvoker.AllocateInputs(); }

  public IAsyncResult InvokeBegin(object instance, object[] inputs, AsyncCallback callback, object state) {
    _myLog.Log("Method " +_operationName + " of class " +_controllerName + " called"); 
    return_baseInvoker.InvokeBegin(instance, inputs, callback, state); 
  }

  public object InvokeEnd(object instance, out object[] outputs, IAsyncResult result) {
    return_baseInvoker.InvokeEnd(instance, out outputs, result);
  }

  public bool IsSynchronous { 
    get {return_baseInvoker.IsSynchronous; } 
  } 
} 

This is where the log is really written. It uses the interface to log which came from Unity from the Factory. The log is written when the method is invoked.