Debugging the WCF Stack

As if starting developing with WCF wasn’t a hard enough paradigm shift what with getting used to sharing schema instead of type and being cruelly abstracted away from all our lovely plumbing, the abstraction itself it can throw some interesting curve-balls. It’s all very well taking the plumbing and abstracting it away but what happens when errors occur down there…out of our reach ? The errors may still be in our code but if they are being hit by the DataContractSerializer for instance it’s hard to handle them or even catch them, for that matter. To illustrate the problem and provide a possible solution, here’s an example.
 
First we’ll create a nice simple service library.
 
using System;
using System.Collections.Generic;
using System.Text;
using System.ServiceModel;
using System.Runtime.Serialization; 

namespace WCFLibrary
{
	[ServiceContract()]
	public interface IMyService
	{
		[OperationContract]
		Thing GetThing(Flavour flavour); 
		
		[OperationContract]
		Thing[] GetOneOfEach();
	} 
	
	public class MyService : IMyService
	{ 
		#region IMyService Members 
		public Thing GetThing(Flavour flavour)
		{
			switch (flavour)
			{
				case Flavour.Orange:
					return new Thing("Ollie", Flavour.Orange);
				case Flavour.Raspberry:
					return new Thing("Roger", Flavour.Raspberry);
				case Flavour.Strawberry:
					return new Thing("Sally", Flavour.Strawberry);
				case Flavour.Banana:
					return new Thing("Bernice", Flavour.Banana);
				default:
					throw new FaultException("No such flavour");
			}
		} 

		public Thing[] GetOneOfEach()
		{
			List<Thing> things = new List<Thing>();
			foreach(Flavour f in Enum.GetValues(typeof(Flavour)))
			{	
				things.Add(this.GetThing(f));
			}
			return things.ToArray();
		} 
		#endregion
	}
	
	public enum Flavour
	{
		Strawberry,
		Raspberry,
		Orange,
		Banana
	} 

	[DataContract]
	public class Thing
	{
		string name;
		Flavour flavour; 
		public Thing(string name, Flavour flavour)
		{
			this.Name = name;
			this.Flavour = flavour;
		}
		
		[DataMember]
		public string Name
		{
			get { return name; }
			set { name = value; }
		} 

		[DataMember]
		public Flavour Flavour
		{
			get { return flavour; }
			set { flavour = value; }
		}
	}
}
Then a host application.
 
using System;
using System.Collections.Generic;
using System.Text; 
using System.ServiceModel;

namespace WCFHost
{
	class Program
	{
		static void Main(string[] args)
		{ 
			using (ServiceHost host = new ServiceHost(
				typeof(WCFLibrary.MyService),	
				new Uri("http://localhost:7001/MyService")))
			{
				host.Closed += new EventHandler(host_Closed);
				host.Open();
				Console.WriteLine(
					"{0} is running at {1}.\nPress any key to close and exit...",
					host.Description.ServiceType.FullName,
					host.BaseAddresses[0].ToString());
				Console.ReadKey(true);
			}	 
		}
		
		static void host_Closed(object sender, EventArgs e)
		{
			Console.WriteLine("{0} closed.",
				((ServiceHost)sender).Description.ServiceType.FullName);
		}
	}
}
With the following config :
 
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
	<system.serviceModel>
		<behaviors>
			<serviceBehaviors>
				<behavior name="MetadataExchange">
					<serviceMetadata httpGetEnabled="true" />
				</behavior>
			</serviceBehaviors>
		</behaviors>
		<services>
			<service behaviorConfiguration="MetadataExchange" 
				name="WCFLibrary.MyService">
			<endpoint address="net.tcp://localhost:7000/MyService" 
				binding="netTcpBinding"
				bindingConfiguration="" name="TCP_7000_MyService"
				contract="WCFLibrary.IMyService" />
			</service>
		</services>
	</system.serviceModel>
</configuration>
And finally having generated a client proxy we can call it like this :
 
using System;
using System.Collections.Generic;
using System.Text; 
using WCFClient.MyService; 
namespace WCFClient
{
	class Program
	{
		static void Main(string[] args)
		{
			using (MyServiceClient proxy = new MyServiceClient())
			{
				foreach (Thing thing in proxy.GetOneOfEach())
				{
					Console.WriteLine("{0} {1}", 
						thing.Name, 
						thing.Flavour.ToString());
				}
			}
			Console.ReadKey(true);
		}
	}
}
Now, we’ll introduce an error in the service that will not be encountered until the Data Contract class is serialized, i.e. it will occur out of scope of the actual service method call. We are going to change this line in our GetThing service method :
 
case Flavour.Banana:
	return new Thing("Bernice", Flavour.Banana);
to this :
 
case Flavour.Banana:
	return new Thing("Bernice", (Flavour)9);
So we are sneakily casting the integer value 9 into the integer-based enum Flavour even though it’s not a valid value of Flavour. I have actually seen a live version of this error where some unexpected integer values got into a database column so the line actually looked more like this :
 
return new Thing("Bernice", (Flavour)reader.GetInt32(3));
When the service is run and called by the client no error is seen in the service even when debugging and the error appears on the client as a timeout. So, imagine this error is intermittent because it only occurs in a very few out of thousands of database records. Some clients are complaining of timeout errors even though the service isn’t busy and there are no errors on the server side. We can’t debug this and there doesn’t seem to be anywhere we can put a try-catch block. What we really need to be able to do is debug into the DataContractSerializer but we can’t. One option is to enable tracing in the service diagnostics. This can be done either using the WCF Configuration Editor :
 
configeditor
 
or by editing the service config :
 
<system.diagnostics>
	<sources>
		<source name="System.ServiceModel" 
			switchValue="Verbose,ActivityTracing"
			propagateActivity="true">
			<listeners>
				<add type="System.Diagnostics.DefaultTraceListener" 
					name="Default">
					<filter type="" />
				</add>
				<add name="ServiceModelTraceListener">
					<filter type="" />
				</add>
			</listeners>
		</source>
	</sources>
	<sharedListeners>
		<add initializeData="c:\temp\app_tracelog.svclog"
			type="System.Diagnostics.XmlWriterTraceListener, System, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"
			name="ServiceModelTraceListener" 
			traceOutputOptions="LogicalOperationStack, DateTime, Timestamp, ProcessId, ThreadId, Callstack">
			<filter type="" />
		</add>
	</sharedListeners>
</system.diagnostics>
If we run the service again and make the same call we can view the resulting trace log in the Service Trace Viewer :
 
traceviewer
 
There we can clearly see the exception that occurred. The great thing about the tracing and the Trace Viewer is that if we run tracing on all the consumers and services for a particular activity and enable activity propagation we can get the trace logs from all participants and the Trace Viewer will stitch them together for us so we can see the whole thing end to end and step through.
 
This approach is great in many instances but sometimes when debugging it’s a bit "after the fact" and actually what you’d like is to be be able to set a break point or have the debugger catch it in the act so you can get in and look at the stack.
 
To help with this we really need our own serializer but the serializers (DataContractSerializer and NetDataContractSerializer) are sealed. However, XmlObjectSerializer that they both inherit from is not and it is this type that is used so maybe be can hook in there somehow. I can create a class that inherits from XmlObjectSerializer but I don’t want to write my own serializer…way too much work. However, I can use this class as a wrapper for the actual serializer and delegate to it. This effectively injects my debuggable code into the hard-to-debug WCF plumbing. Here’s my DebuggableDataContractSerializer :
 
public class DebuggableDataContractSerializer : XmlObjectSerializer
{
	private XmlObjectSerializer _Serializer;
	
	public DebuggableDataContractSerializer(XmlObjectSerializer serializerToUse)
	{
		if (serializerToUse == null)
		{
			throw new ArgumentException("Argument cannot be null.", "serializerToUse");
		}
		this._Serializer = serializerToUse;
	}
	
	public override bool Equals(object obj)
	{
		return this._Serializer.Equals(obj);
	}
		
	public override bool IsStartObject(XmlDictionaryReader reader)
	{
		return this._Serializer.IsStartObject(reader);
	}
	
	public override object ReadObject(XmlDictionaryReader reader)
	{
		return this._Serializer.ReadObject(reader);
	}
	
	public override object ReadObject(XmlReader reader)
	{
		return this._Serializer.ReadObject(reader);
	} 
	
	public override object ReadObject(XmlReader reader, bool verifyObjectName)
	{
		return this._Serializer.ReadObject(reader, verifyObjectName);
	}
	
	public override string ToString()
	{
		return this._Serializer.ToString();
	}
	
	public override int GetHashCode()
	{
		return this._Serializer.GetHashCode();
	}
	
	public override bool IsStartObject(XmlReader reader)
	{
		return this._Serializer.IsStartObject(reader);
	}
	
	public override object ReadObject(System.IO.Stream stream)
	{
		return this._Serializer.ReadObject(stream);
	}
	
	public override object ReadObject(XmlDictionaryReader reader, bool verifyObjectName)
	{
		return this._Serializer.ReadObject(reader, verifyObjectName);
	} 

	public override void WriteEndObject(XmlDictionaryWriter writer)
	{
		this._Serializer.WriteEndObject(writer);
	} 
	
	public override void WriteEndObject(XmlWriter writer)
	{
		this._Serializer.WriteEndObject(writer);
	} 
	
	public override void WriteObject(System.IO.Stream stream, object graph)
	{
		this._Serializer.WriteObject(stream, graph);
	} 
	
	public override void WriteObject(XmlDictionaryWriter writer, object graph)
	{
		this._Serializer.WriteObject(writer, graph);
	} 
	
	public override void WriteObject(XmlWriter writer, object graph)
	{
		this._Serializer.WriteObject(writer, graph);
	} 
	
	public override void WriteObjectContent(XmlDictionaryWriter writer, object graph)
	{
		this._Serializer.WriteObjectContent(writer, graph);
	} 
	
	public override void WriteObjectContent(XmlWriter writer, object graph)
	{
		this._Serializer.WriteObjectContent(writer, graph);
	} 
	
	public override void WriteStartObject(XmlDictionaryWriter writer, object graph)
	{
		this._Serializer.WriteStartObject(writer, graph);
	} 
	
	public override void WriteStartObject(XmlWriter writer, object graph)
	{
		this._Serializer.WriteStartObject(writer, graph);
	}
}
Now I need to get my serializer swapped out with the real one. I remembered seeing a blog post by Aaron Skonnard way back in April ’06 in which he showed how to substitute the NetDataContractSerializer for the DataContractSerializer so let’s try that here :
 
public class DebuggableSerializer : Attribute, IOperationBehavior
{ 
	public void AddBindingParameters(OperationDescription description,
		BindingParameterCollection parameters)
	{
	}
	
	public void ApplyClientBehavior(OperationDescription description,
		ClientOperation proxy)
	{
		ReplaceDataContractSerializerOperationBehavior(description);
	} 
	
	public void ApplyDispatchBehavior(OperationDescription description,
		DispatchOperation dispatch)
	{
		ReplaceDataContractSerializerOperationBehavior(description);
	} 
	
	public void Validate(OperationDescription description)
	{
	} 
	
	private static void ReplaceDataContractSerializerOperationBehavior(
		OperationDescription description)
	{
		DataContractSerializerOperationBehavior dcsOperationBehavior =
			description.Behaviors.Find<DataContractSerializerOperationBehavior>();
		if (dcsOperationBehavior != null)
		{
			description.Behaviors.Remove(dcsOperationBehavior);
			description.Behaviors.Add(
				new DebuggableDataContractSerializerOperationBehavior(description));
		}
	}
} 
	
public class DebuggableDataContractSerializerOperationBehavior
		: DataContractSerializerOperationBehavior
{
	
	public DebuggableDataContractSerializerOperationBehavior(
		OperationDescription operationDescription) : base(operationDescription)
	{ 
	} 
	
	public override XmlObjectSerializer CreateSerializer(Type type, string name,
	string ns, IList<Type> knownTypes)
	{
		DataContractSerializer dcs = new DataContractSerializer(type, name,
			ns, knownTypes);
		DebuggableDataContractSerializer mdcs = new DebuggableDataContractSerializer(dcs);
		return mdcs;
	} 
	
	public override XmlObjectSerializer CreateSerializer(Type type,
		XmlDictionaryString name,
		XmlDictionaryString ns, IList<Type> knownTypes)
	{
		DataContractSerializer dcs = new DataContractSerializer(type, name, ns, knownTypes);
		DebuggableDataContractSerializer mdcs = new DebuggableDataContractSerializer(dcs);
		return mdcs;
	}
}
Now we add our new custom attribute to our service method and we are good to go.
 
[ServiceContract()]
public interface IMyService
{
	[OperationContract]
	[DebuggableSerializer]
	Thing GetThing(Flavour flavour); 

	[OperationContract]
	[DebuggableSerializer]
	Thing[] GetOneOfEach();
}
 
debugging
 
I have since written an article on how to extend this concept so that it can be used as a ServiceBehavior, ContractBehavior or EndpointBehavior. See Extending the WCF Stack.

Advertisements

2 Responses to Debugging the WCF Stack

  1. David says:

    Do you have any idea how much time I wasted yesterday with a serializer issue?  Not to say that my problem is fixed, but at least now I can actually work on fixing it. THANK YOU!

  2. Pingback: Extending the WCF Stack « Overflow…

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: