Easing The Pain Of WCF Debugging
Posted by Davy Brion on August 20th, 2008
WCF is pretty cool, i guess. It’s quite powerful, and it’s so configurable it even has options to control the speed of the CPU fans of the users of your service. Ok, maybe you can’t really configure that, but with approximately 12.4 billion WCF configuration settings available to you, who knows? But the biggest problem i have with WCF is the painful debugging experience when something goes wrong.
Ever got a client-side exception that looked like this?
[SocketException (0x2746): An existing connection was forcibly closed by the remote host]
System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags) +73
System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing) +110
[CommunicationException: The socket connection was aborted. This could be caused by an error processing your message or a receive timeout being exceeded by the remote host, or an underlying network resource issue. Local socket timeout was '00:29:59.8590000'.]
System.ServiceModel.Channels.SocketConnection.ReadCore(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout, Boolean closing) +183
System.ServiceModel.Channels.SocketConnection.Read(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout) +54
System.ServiceModel.Channels.DelegatingConnection.Read(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout) +32
System.ServiceModel.Channels.ConnectionStream.Read(Byte[] buffer, Int32 offset, Int32 count, TimeSpan timeout) +32
System.ServiceModel.Channels.ConnectionStream.Read(Byte[] buffer, Int32 offset, Int32 count) +53
System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count) +37
System.Net.Security.NegotiateStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) +131
System.Net.Security.NegotiateStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) +28
System.Net.Security.NegotiateStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) +223
[IOException: The read operation failed, see inner exception.]
System.Net.Security.NegotiateStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) +333
System.Net.Security.NegotiateStream.Read(Byte[] buffer, Int32 offset, Int32 count) +79
System.ServiceModel.Channels.StreamConnection.Read(Byte[] buffer, Int32 offset, Int32 size, TimeSpan timeout) +72
[CommunicationException: The socket connection was aborted. This could be caused by an error processing your message or a receive timeout being exceeded by the remote host, or an underlying network resource issue. Local socket timeout was '00:29:59.8590000'.]
System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg) +7594687
System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type) +275
Rather messy, no? Does it give you any clue as to what could possibly be wrong? Nope. This particular client-side exception occurs when something goes wrong server-side, at some point after you’ve already returned your return value in your service implementation. Of course, you don’t actually see it happening server-side. So i tried setting IncludeExceptionDetailInFaults to true on the service implementation… didn’t make a difference. I set IncludeExceptionDetailInFaults to true on the service host but that didn’t work either. Sigh.
After some Live Searching (i was actually googling, but let’s make Microsoft think at least someone outside of Redmond uses Live Search) i discovered that you can enable WCF tracing. Bingo! Why didn’t Juval Lowy’s book mention this? It’s supposed to be the WCF Bible…. Oh well, thanks to Google, i mean Live Search, we now know how to enable WCF’s tracing:
<system.diagnostics>
<trace autoflush="true" />
<sources>
<source name="System.ServiceModel"
switchValue="Information, ActivityTracing"
propagateActivity="true">
<listeners>
<add name="wcfTraceListener" type="System.Diagnostics.XmlWriterTraceListener" initializeData="WcfTrace.svclog" />
</listeners>
</source>
</sources>
</system.diagnostics>
You can also use the Service Configuration Editor tool which is available in the Windows SDK, but spare yourself the pain of that tool and just copy/paste this xml in your config file.
Now run the service again, and do whatever it was that triggered the weird client-side exception. After the exception occurred, open the WcfTrace.svclog file with either an editor (it’s not very readable though) or with the Microsoft Service Trace Viewer tool (which is not too bad actually).
When i opened my trace output, i immediately saw a red item in the Activity list… so i clicked on it, and i finally saw the problem:
There was an error while trying to serialize parameter http://tempuri.org/:ProcessReadOnlyRequestsResult. The InnerException message was ‘Maximum number of items that can be serialized or deserialized in an object graph is ’65536′. Change the object graph or increase the MaxItemsInObjectGraph quota. ‘. Please see InnerException for more details.
There we go… the client-side exception was terribly useless, but this is the best kind of exception: not only is it clear about what’s wrong, it even gives you the solution to the problem. Btw, if you get that client-side exception, it doesn’t mean that your problem will be the same as the one listed here. It could literally be anything if it doesn’t happen inside of your service implementation. I’ve seen the same client-side exception when one type somewhere in the object graph didn’t have a DataContract attribute, for instance.
So anyways, do yourself a favor and enable WCF tracing while you’re still in development… it could save you a lot of time.
Oh and bonus points go to whoever points out which of WCF’s many configuration settings actually make the real exception appear in the client-side stacktrace

August 21st, 2008 at 12:46 am
Attempted grab for bonus points: Set IncludeExceptionDetailInFaults attribute to true
August 21st, 2008 at 6:50 am
No that’s not it… the post mentions that i tried that
August 21st, 2008 at 11:26 am
Missed that bit sorry.
Did you try it on the ServiceBehavior? (see web.config example on msdn).
I got it working at my last job but don’t have the code to reference now :-\
August 21st, 2008 at 11:30 am
yup, tried it on both levels: ServiceBehavior and setting it on the ServiceHost explicitely
But i believe that setting only applies to FaultExceptions that occur while you’re within your service operation
the problem i’m describing in this post is something that happens _after_ your operation has executed, but before the result is sent back to the client… inside of WCF’s plumbing basically
August 21st, 2008 at 11:39 am
Btw, there is a kewl tool for reading WCF trace info called Service Trace Viewer. I wrote quick post about it here.
August 21st, 2008 at 11:39 am
yea, mentioned that in the post too :p
August 21st, 2008 at 12:03 pm
Ugh, sorry mate. My past experiences with WCF force me to tune out as a sanity-protection measure when confronted with it again :$
I had a screenshot though! That’s gotta count for something right? Or just delete all my comments and let’s never speak of this again
August 21st, 2008 at 12:05 pm
no… i’ll leave them here as a valid illustration of the possible consequences of prolonged WCF usage :p
April 25th, 2009 at 6:18 pm
Big help, found my problem of “The service does not allow you to log on anonymously” which only happened in certain scenarios and wasn’t logged anywhere.
March 11th, 2010 at 6:23 pm
Brion, Did anyone got the bonus points. Can you share the configuration settings which make the real exception appear in the client-side.
March 12th, 2010 at 12:14 am
Great info. This just made my day.