How to add custom context data to be logged with Policy Injection in WCF?

Question

We all know it's perfectly ok to marry up WCF with PIAB to address cross cutting concerns like logging, validation, auditing etc (visit http://msdn.microsoft.com/en-us/magazine/cc136759.aspx).

But the bog standard log call handler only support a limited set of "extended properties" for the logs. What if there are requirements for additional information to be logged such as: client Ip address, user id etc?

Answer (will be added as an answer later due to stackoverflow's strange policy on members with low ratings):

Answer 1

After much digging around I came up with this solution which I hope will benefit others with the same query.

First of all, you need to have a custom call handler to include all the additional data you want for your logs. You can refer to the entlib source code and look for LogCallHandler. Add the additional data in GetLogEntry private method:

    private TraceLogEntry GetLogEntry(IMethodInvocation input)
    {
        var logEntry = new CustomLogEntry();
        var formatter = new CategoryFormatter(input.MethodBase);
        foreach (string category in categories)
        {
            logEntry.Categories.Add(formatter.FormatCategory(category));
        }

        //slot = Thread.GetNamedDataSlot("PatientId");
        //logEntry.PatientId = Thread.GetData(slot).ToString();
        //logEntry.PatientId = CallContext.GetData("__PatientId").ToString();
        logEntry.AppName = ApplicationContext.Current["AppName"].ToString();
        logEntry.ClientIp = ApplicationContext.Current["ClientIp"].ToString();
        logEntry.UserId = ApplicationContext.Current["UserId"].ToString();
        logEntry.PatientId = ApplicationContext.Current["PatientId"].ToString();
        logEntry.EventId = eventId;
        logEntry.Priority = priority;
        logEntry.Severity = severity;
        logEntry.Title = LogCallHandlerDefaults.Title;

        if (includeParameters)
        {
            Dictionary<string, object> parameters = new Dictionary<string, object>();
            for (int i = 0; i < input.Arguments.Count; ++i)
            {
                parameters[input.Arguments.GetParameterInfo(i).Name] = input.Arguments[i];
            }

            logEntry.ExtendedProperties = parameters;
        }

        if (includeCallStack)
        {
            logEntry.CallStack = Environment.StackTrace;
        }

        logEntry.TypeName = input.Target.GetType().FullName;
        logEntry.MethodName = input.MethodBase.Name;
        return logEntry;
    }

After thatn, you have to creat the infrastruture to propagate context data from client to server. I have a wrapper class for CallContext to store a dictionary object for context data:

[Serializable]
public class ApplicationContext : Dictionary<string, object>
{
    private const string CALL_CONTEXT_KEY = "__Context";
    public const string ContextHeaderLocalName = "__Context";
    public const string ContextHeaderNamespace = "urn:tempuri.org";

    private static void EnsureSerializable(object value)
    {
        if (value == null)
        {
            throw new ArgumentNullException("value");
        }
        if (!value.GetType().IsSerializable)
        {
            throw new ArgumentException(string.Format("The argument of the type \"{0}\" is not serializable!", value.GetType().FullName));
        }
    }

    public new object this[string key]
    {
        get { return base[key]; }
        set
        { EnsureSerializable(value); base[key] = value; }
    }

    public int Counter
    {
        get { return (int)this["__Count"]; }
        set { this["__Count"] = value; }
    }

    public static ApplicationContext Current
    {
        get
        {
            if (CallContext.GetData(CALL_CONTEXT_KEY) == null)
            {
                CallContext.SetData(CALL_CONTEXT_KEY, new ApplicationContext());
            }

            return CallContext.GetData(CALL_CONTEXT_KEY) as ApplicationContext;
        }
        set
        {
            CallContext.SetData(CALL_CONTEXT_KEY, value);
        }
    }
}

On the service client, this context will be added to the request message header through implementing IClientMessageInspector.

public class ClientAuditInfoInspector : IClientMessageInspector
{
    #region Implementation of IClientMessageInspector

    public object BeforeSendRequest(ref Message request, IClientChannel channel)
    {
        var contextHeader = new MessageHeader<ApplicationContext>(ApplicationContext.Current);
        request.Headers.Add(contextHeader.GetUntypedHeader(ApplicationContext.ContextHeaderLocalName, ApplicationContext.ContextHeaderNamespace));
        return null;
    }

    public void AfterReceiveReply(ref Message reply, object correlationState)
    {
        if (reply.Headers.FindHeader(ApplicationContext.ContextHeaderLocalName, ApplicationContext.ContextHeaderNamespace) < 0) { return; }
        var context = reply.Headers.GetHeader<ApplicationContext>(ApplicationContext.ContextHeaderLocalName, ApplicationContext.ContextHeaderNamespace);
        if (context == null) { return; }
        ApplicationContext.Current = context;
    }

    #endregion
}

On the service side, I have a custom implementation of ICallContextInitializer to retrieve the message header from the incoming message and set it back to the outgoing message:

public class AuditInfoCallContextInitializer : ICallContextInitializer
{
    #region Implementation of ICallContextInitializer
    /// <summary>
    /// Extract context data from message header through local name and namespace,
    /// set the data to ApplicationContext.Current.
    /// </summary>
    /// <param name="instanceContext"></param>
    /// <param name="channel"></param>
    /// <param name="message"></param>
    /// <returns></returns>
    public object BeforeInvoke(InstanceContext instanceContext, IClientChannel channel, Message message)
    {
        var context = message.Headers.GetHeader<ApplicationContext>(ApplicationContext.ContextHeaderLocalName, ApplicationContext.ContextHeaderNamespace);
        if (context == null) { return null; }

        ApplicationContext.Current = context;
        return ApplicationContext.Current;

    }

    /// <summary>
    /// Retrieve context from correlationState and store it back to reply message header for client.
    /// </summary>
    /// <param name="correlationState"></param>
    public void AfterInvoke(object correlationState)
    {
        var context = correlationState as ApplicationContext;
        if (context == null)
        {
            return;
        }
        var contextHeader = new MessageHeader<ApplicationContext>(context);
        OperationContext.Current.OutgoingMessageHeaders.Add(contextHeader.GetUntypedHeader(ApplicationContext.ContextHeaderLocalName, ApplicationContext.ContextHeaderNamespace));
        ApplicationContext.Current = null;

    }

    #endregion
}

This essentially is a round trip for the message header payload to travel. In the AfterInvoke method, the message header could be modified before being sent back. Finally, I have created an endpoint behaviour to apply the MessageInspector and CallContextInitializer.

public class AuditInfoContextPropagationEndpointBehavior : BehaviorExtensionElement, IEndpointBehavior
{
    #region Overrides of BehaviorExtensionElement

    protected override object CreateBehavior()
    {
        return new AuditInfoContextPropagationEndpointBehavior();
    }

    public override Type BehaviorType
    {
        get { return typeof(AuditInfoContextPropagationEndpointBehavior); }
    }

    #endregion

    #region Implementation of IEndpointBehavior

    public void Validate(ServiceEndpoint endpoint)
    {
        return;
    }

    public void AddBindingParameters(ServiceEndpoint endpoint, BindingParameterCollection bindingParameters)
    {
        return;
    }

    public void ApplyDispatchBehavior(ServiceEndpoint endpoint, EndpointDispatcher endpointDispatcher)
    {
        foreach (var operation in endpointDispatcher.DispatchRuntime.Operations)
        {
            operation.CallContextInitializers.Add(new AuditInfoCallContextInitializer());
        }

    }

    public void ApplyClientBehavior(ServiceEndpoint endpoint, ClientRuntime clientRuntime)
    {
        clientRuntime.MessageInspectors.Add(new ClientAuditInfoInspector());
    }

    #endregion
}

You could also write a contract behaviour to achieve the same by decorating your service/contract with the behaviour attribute.

Now from your service client, you can set all the context data like below:

using (var channelFactory = new ChannelFactory<ICustomerService>("WSHttpBinding_ICustomerService"))
        {
            var client = channelFactory.CreateChannel();
            ApplicationContext.Current["AppName"] = "Test application";
            ApplicationContext.Current["ClientIp"] = @"1.1.0.1";
            ApplicationContext.Current["UserId"] = "foo";
            ApplicationContext.Current["PatientId"] = "bar123";

            Console.WriteLine("Retreiving Customer 1");
            Customer cust = client.GetCustomer("1");
            Console.WriteLine("Retreived Customer, Name: [" + cust.Name + "]");
        }

This is also posted on the discussion board of entlib.codeplex at: http://entlib.codeplex.com/discussions/266963