WCF Trace Tool

I've been doing a fair bit of WCF lately. And an absolute nightmare of an error to try to debug is the "Channel was in a faulted state" error. This is a very generic error and doesn't really say much at all about the cause of the error. The way WCF communicates is through channels. When a channel is in the faulted state, it means the construction and opening of a channel failed for some reason, and the channel faulted. Once in the faulted state a channel cannot be used. It must be constructed again. So how do I debug this issue and resolve the cause of the error? If only there were some way of getting more information out of the channel creation process. Enter the WCF Trace Tool. WCF traces a fair bit of information when it's doing it's thing. There's a lot going on under the hood, and Microsoft realise that we need to know what exactly is going on. So now all we have to do, is catch that trace. Open up web.config and add the following configuration to /configuration/system.serviceModel:

<diagnostics performanceCounters="All" wmiProviderEnabled="true">
  <messageLogging logEntireMessage="true" logMalformedMessages="true"
    logMessagesAtServiceLevel="true" logMessagesAtTransportLevel="true"
    maxMessagesToLog="100000"/>
</diagnostics>

Then add the following to /configuration/system.diagnostics:

<sharedListeners>
  <add name="sharedListener"
    type="System.Diagnostics.XmlWriterTraceListener"
    initializeData="c:\logs\servicetrace.svclog" />
</sharedListeners>
<sources>
  <source name="System.ServiceModel" switchValue="Verbose,
    ActivityTracing" >
    <listeners>
      <add name="sharedListener" />
    </listeners>
  </source>
  <source name="System.ServiceModel.MessageLogging"
    switchValue="Verbose">
    <listeners>
      <add name="sharedListener" />
    </listeners>
  </source>
</sources>

Thank Michele Leroux Bustamante for this info from her blog entry SvcTraceViewer.exe - Learn it, Know it, Love it. Now when WCF is invoked, an XML trace file is written to the location above in the initializeData attribute. You could try inspecting this file in a text or XML editor, but the easiest way to inspect it is to use the WCF Trace Viewer which ships with the .net 3.0 SDK. This can be found at c:\Program Files\Microsoft Visual Studio 9.0\SvcTraceViewer.exe (that might only be the location if you have VS installed). Just execute this program and load the XML trace file into it using the file menu. Now I can inspect the process of channel creation, servicing requests, and channel destruction. If I get an error it will be highlighted red. Now let me tell you about what I was doing when I found this tool, as I reckon this is a pretty cool feature of WCF. Being that I'm building web sites, I of course usually host my WCF services in IIS. IIS only supports the HTTP protocols. As we all know HTTP only supports request / response calls. A server cannot send data to a client unless it is a response to a request. But WCF allows us to get around this limitation of HTTP, by using the duplex channel. A duplex channel facilitates two way communication between a client and the server. How is this done? When the client sets up it's channel, it communicates with the server and registers itself. To allow the server to call back into the client, the client sets up it's own WCF service and tells the server about it, so the server can just call the service hosted by the client. So to facilitate two way communication, each machine hosts it's own service which the other machine makes calls to. And the client side service is completely transparent to the developer. So what did I need the trace tool for? Initially I was hosting the service I had issues with on the same machine as I was calling it from. Whilst both the server and the client were the same machine, I didn't have any issues. I then moved the service onto another machine that was only connected to the first through a VPN. All of a sudden I started getting the faulted channel error. After enabling the trace and reading it in the trace viewer I could see the call where the client registers it's callback service with the server. And I could see that the host name the client was sending to the server was the internal machine name which wouldn't resolve through the VPN. After I changed this by setting the clientBaseAddress attribute on the binding, and applying the appropriate security, all worked fine. I never would have worked this out had it not been for the trace viewer. I could have ripped out wireshark (you know it's a bad day when you have to rip out wireshark :) ), but this was a production server where the error was occurring, and I wouldn't have liked to deploy such a heavy tool to work it out. I hope this save you some sanity.