WCF - IClientMessageInspector - Wrong principal in AfterReceiveReply

Viewed 118

Context

I've got .NET Framework 4.6.1 WebApi application. This application calls various web services. Therefore I've made an implementation of IClientMessageInspector in order to do some logging of WCF (SOAP) requests/replies.

Issue

However after some time I've realized that some replies are logged under a different principal, i.e. principal A makes a request and receives a reply and yet the response is logged under principal B.

Below is a simplified minimalistic example of the implementation just to demonstrate the issue.

    public class MyClientMessageInspector : IClientMessageInspector
    {
        public object BeforeSendRequest(ref Message request, IClientChannel channel)
        {
            var correlationState = new CorrelationState
            {
                Guid = Guid.NewGuid()
            };

            // Principal A
            Debug.WriteLine(Thread.CurrentPrincipal);

            // Guid: 2abf9a7b-dac2-4c0d-b38d-1cdfb95405a7
            Debug.WriteLine(correlationState.Guid);

            return correlationState;
        }

        public void AfterReceiveReply(ref Message reply, object correlationStateObject)
        {
            var correlationState = (CorrelationState) correlationStateObject;

            // Principal B - How come???
            Debug.WriteLine(Thread.CurrentPrincipal);            

            // Guid: 2abf9a7b-dac2-4c0d-b38d-1cdfb95405a7 (matches Guid from request)
            Debug.WriteLine(correlationState.Guid);
        }
    }

Both Thread.CurrentPrincipal and HttpContext.CurrentUser are only set in the Global.asax.cs in the Application_PostAuthenticateRequest event.

The application heavily utilizes async/await paradigm and almost every async call (including calls of the web services) is followed by .ConfigureAwait(false). However my understanding is that Thread.CurrentPrincipal is flowed between threads reagardless of the usage of ConfigureAwait(false). That seems to be true since all my other logs are made under a correct principal, even those that happen after AfterReceiveReply.

Question

Is there an explanation why Thread.CurrentPrincipal in AfterReceiveReply contains a different principal? I know how to workaround this issue - I could send the principal between BeforeSendRequest and AfterReceiveReply within the CorrelationState object. But before doing so I need to understand why my code behaves differently than expected and also if there is possibly a better solution than the workaround.

1 Answers

When you use .ConfigureAwait(false) on an application with a threadpool any of the threads in the pool might be chosen to continue execution. Some of those threads might have the same context as your originating thread, others might have different contexts. You have no control over what thread takes over once you use .ConfigureAwait(false).

There is a more detailed description of what's going on here: https://medium.com/rubrikkgroup/understanding-async-avoiding-deadlocks-e41f8f2c6f5d

The above article talks about using .Result and Task.Run, not .ConfigureAwait(false) however .ConfigureAwait(false) effectively does this behind the scenes anyway if you ever call a .wait() or .result on the call anywhere in your call stack. Importantly this only happens if your code is actually waiting for something. If your async methods happen to have the data they need to continue they will happily stay on their original thread and the context variables will match.

Also when running Async with .ConfigureAwait(false) you can be sent from your first thread to another thread, then back to your first thread if it's free and the code needed to wait for something like a network read. The threadpool means you have a limited number of threads that can be called on and most operations that involve threads don't actually spin up a completely new one.

Some further reading that might help: https://devblogs.microsoft.com/dotnet/configureawait-faq/

Related