WCF IClientMessageInspector Logging Discrepancy Regarding Action

Question

I am logging outgoing WCF Soap requests from my application, and discovered a discrepancy between what I'm logging and what actually goes out to the server via the wire.

Here is what I'm logging:

 <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
 <s:Header>
    <Action s:mustUnderstand="1" xmlns="http://schemas.microsoft.com/ws/2005/05/addressing/none">http://tempuri.org/myinterface</Action>
 </s:Header>
 <s:Body>
    <myinterface xmlns="http://tempuri.org/">
    ...

Here is what actually goes out (captured with WireShark):

 <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/">
 <s:Body>
   <myinterface xmlns="http://tempuri.org/">
   ...

You'll notice that the WireShark capture does not have the Header or Action elements.

I only noticed this because I tried pushing my logged request out through SoapUI.

I'm using this code to log the request:

public class InspectorBehavior : IEndpointBehavior
{
    public void ApplyClientBehavior(ServiceEndpoint endpoint, ClientRuntime clientRuntime)
    {
        clientRuntime.MessageInspectors.Add(new WCFMessageInspector());
    }

And:

public class WCFMessageInspector : IClientMessageInspector
{ 
    public object BeforeSendRequest(ref System.ServiceModel.Channels.Message request, IClientChannel channel)
    {
        Log(request.ToString());

        return null;
    }

And:

    client.Endpoint.Address = new System.ServiceModel.EndpointAddress(address);
    client.Endpoint.Behaviors.Add(new InspectorBehavior());

Does anyone know if there's a way to capture exactly what is going out (verbatim), without any post-processing as shown above?

Answer 1

You can configure WCF Message Logging in your App.config to log messages at transport level.

This should capture the message as late as possible:

For outgoing messages, logging happens immediately after the message leaves user code and immediately before the message goes on the wire.

<system.diagnostics>
  <sources>
      <source name="System.ServiceModel.MessageLogging">
        <listeners>
                 <add name="messages"
                      type="System.Diagnostics.XmlWriterTraceListener"
                      initializeData="c:\logs\messages.svclog" />
        </listeners>
      </source>
    </sources>
</system.diagnostics>

<system.serviceModel>
  <diagnostics>
        <messageLogging 
         logEntireMessage="true" 
         logMalformedMessages="true"
         logMessagesAtServiceLevel="false" 
         logMessagesAtTransportLevel="true"
         maxMessagesToLog="1000"
         maxSizeOfMessageToLog="1000000"/>
  </diagnostics>
</system.serviceModel>

Answer 2

You can capture exact content via custom MessageEncoder, unlike message inspectors (IDispatchMessageInspector / IClientMessageInspector) it sees original byte content including any malformed XML data.

However it's a bit harder to implement this approach. You have to wrap a standard textMessageEncoding as custom binding element and adjust config file to use that custom binding.

Also you can see as example how I did it in my project - wrapping textMessageEncoding, logging encoder, custom binding element and config.