You can count on WCF

One of the many great things about WCF which you don’t often hear people talking about is that it comes fully instrumented out of the box. That’s right, the WCF runtime has full instrumentation baked right in, ready for you to use to performance profile and monitor your services and all you have to do to start using it is flick a switch in your service config and run performance monitor (perfmon.exe).
 
If you’ve been a serious windows user for any length of time you will almost certainly have come across perfmon. It is one of the essential tools for quick, easy system and application profiling and many applications (like SQL Server, MSMQ, the CLR, the WCF Runtime, ASP.NET etc) come with their own specific perfmon counters which let you peek under the hood when they are running. Perfmon lets you capture and display data generated by these counters, monitor customized thresholds and take actions when thresholds are breached. It is a massively useful tool.
 
WCF adds four sets of counters to the system. The first three are ServiceModelService, ServiceModelEndpoint and ServiceModelOperation. As you can probably guess from the names, these counters give you different levels of granularity when profiling so you can capture data at the service level, at the endpoint level and at the individual service method level. The final one is SMSvcHost. This is a set of instrumentation counters attached to the .NET TCP Port Sharing Service that lets different services listen on the same port and I will leave this set for another time.
The first three contain the counters listed below (or a subset thereof) :
 

  • Calls
  • Call Duration
  • Calls Failed
  • Calls Failed Per Second
  • Calls Faulted
  • Calls Faulted Per Second
  • Calls Outstanding
  • Instances
  • Instances Created Per Second
  • Queued Messages Dropped
  • Queued Messages Dropped Per Second
  • Queued Messages Rejected
  • Queued Messages Rejected Per Second
  • Queued Poison Messages
  • Queued Poison Messages Per Second
  • Reliable Messaging Messages Dropped
  • Reliable Messaging Messages Dropped Per Second
  • Reliable Messaging Sessions Faulted
  • Reliable Messaging Sessions Faulted Per Second
  • Security Calls Not Authorized
  • Security Calls Not Authorized Per Second
  • Security Validation and Authentication Failures
  • Security Validation and Authentication Failures Per Second
  • Transacted Operatoins Aborted
  • Transacted Operations Aborted Per Second
  • Transacted Operations Committed
  • Transacted Operations Committed Per Second
  • Transacted Operations In Doubt
  • Transacted Operations In Doubt Per Second
  • Transactions Flowed
  • Transactions Flowed Per Second

Now, I mentioned the flick of a switch in the service config to enable this feature which is off by default, so here it is :

 

<system.serviceModel>
    <diagnostics wmiProviderEnabled="false" performanceCounters="All" />
    <!--
      ... your other service config here...
    -->
</system.serviceModel>
 
That’s all that is required. As you can see, it is also possible to provide access to this instrumentation via WMI by switching the value of the wmiProviderEnabled attribute to true so you can write your own monitoring tools and scripts or use other 3rd party tools that use WMI.
 
As an example I have written a very simple service class :
 
using System;
using System.ServiceModel;
using System.Runtime.Serialization;

namespace WCFTestService
{

    [ServiceContract]
    public interface IMyService
    {

        [OperationContract]
        Foo GetFoo();

        [OperationContract]
        void SetFoo(Foo foo);

    }

    [ServiceBehavior(InstanceContextMode=InstanceContextMode.Single)]
    public class MyService : IMyService
    {

        #region IMyService Members

        public Foo GetFoo()
        {
            System.Threading.Thread.Sleep(200);
            return new Foo("Hello");
        }

        public void SetFoo(Foo foo)
        {
            System.Threading.Thread.Sleep(200);
            Console.WriteLine("Bar = " + foo.Bar);
        }

        #endregion
    }

    [DataContract]
    public class Foo
    {

	public Foo(string bar)
	{
		this.Bar = bar;
	}

	private string _Bar = string.Empty;
	[DataMember]
         public string Bar
         {
            get
            {
                return this._Bar;
            }
            set
            {
                this._Bar = value;
            }
         }
    }
}
 
A simple host executable :
 
using System;
using System.ServiceModel;

namespace WCFTestHost
{
    class Program
    {
        static void Main(string[] args)
        {
            ServiceHost host = new ServiceHost(typeof(WCFTestService.MyService), new Uri("http://localhost:7001/MyService"));
            host.Open();
            Console.WriteLine("Service Running. Press any key to exit...");
            Console.ReadKey();
        }
    }
}

…and here is the config for the host executable :

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
	<system.serviceModel>
		<diagnostics wmiProviderEnabled="false" performanceCounters="All" />
		<behaviors>	
			<serviceBehaviors>
				<behavior name="MetadataExchange">
					<serviceMetadata httpGetEnabled="true" />
				</behavior>
			</serviceBehaviors>
		</behaviors>
		<services>
			<service behaviorConfiguration="MetadataExchange" 
				name="WCFTestService.MyService">
				<endpoint 
					address="net.tcp://localhost:7000/MyService" 
					binding="netTcpBinding" 
					contract="WCFTestService.IMyService" />
			</service>
		</services>
	</system.serviceModel>
</configuration>
Finally, here is a multi-threaded test consumer for the service:
 
using System;
using System.Collections.Generic;
using System.Threading;
using WCFTestClient.WCFTestService;

namespace WCFTestClient{

	class Program 
	{ 
		static void Main(string[] args) 
		{ 
			try 
			{ 
				WaitCallback fire = delegate(object proxy) { 
					Random r = new Random(System.Environment.TickCount); 
					int i = r.Next(1,3); 
					if (i==1) 
					{ 
						string s = ((MyServiceClient)proxy).GetFoo().Bar; 
						Console.WriteLine(System.Threading.Thread.CurrentThread.ManagedThreadId.ToString() + " : " + s); 
					} 
					else 
					{ 
						((MyServiceClient)proxy).SetFoo(new Foo(){Bar = System.Threading.Thread.CurrentThread.ManagedThreadId.ToString()}); 
					} 
					
					using (proxy as IDisposable) { } 
				};
					
				Action<MyServiceClient> queueUp = delegate(MyServiceClient proxy) 
				{ 
					ThreadPool.QueueUserWorkItem(fire, proxy); 
				};
				
				List<MyServiceClient> proxies = new List<MyServiceClient>(); 
				
				for (int i = 0; i < 100; i++) { 
					proxies.Add(new MyServiceClient()); 
				} 
				
				proxies.ForEach(queueUp); 
			} 
			catch(Exception ex) 
			{ 
				Console.WriteLine(ex.ToString()); 
			} 
			
			Console.ReadKey(); 
		} 
	}
}
 
So, here are the facts. The service is configured as a singleton. I have inserted a Thread.Sleep(200) into both methods to simulate more complex activity. The client is multi-threaded (via the thread pool) and will create 100 proxies which will randomly call one of the two service methods.
 
What is this likely to mean in performance terms ? Well, firstly services are inherently single threaded meaning that they will only process one call at a time. Therefore, if the call duration on our service is 200 miliseconds (give or take) then the best performance in terms of calls processed per second we can hope for is 5.
 
So let’s profile our service and see if we’re right. Here’s our output :
 
snap01
 
As you can see our 100 proxies made 100 service calls and our singleton made sure that there was only ever one instance processing those calls so instances created per second briefly hit 1.
 
Call duration averaged at .0201 seconds thanks to our Thread.Sleep(200) and as a result calls max per second was 5.009.
 
So what happens if we reduce our call duration to 100 milliseconds (Thread.Sleep(100)) ? What we should see is calls taking half as long and therefore being processed twice as fast.
 
snap02
 
The graph is pretty much identical except that max calls per second is now 10 and the 100 calls have been processed in half the time. As predicted.
 
You can continue this testing increasing the sleep latency up to somewhere between 800 and 900 milliseconds after which the client will throw an exception when it fails to connect with the service with in the default 1 second timeout. After that you either have to increase the timeouts on the consumer, increase the ListenBacklog or MaxConnections (which both default to 10) on the service, reduce the latency of the service, reduce the number of concurrent calls, abandon the singleton in favour of PerCall instance mode or set the ConcurrencyMode of the singleton to Multiple so that it can be accessed by multiple threads.
 
<gotchas>
1) If you want to monitor a specific service instance then the instance must be running when you go to add the counters to the graph.
2) When the service instance stops running the graph will freeze (i.e. stop capturing data) but will restart when you restart the service.
3) Setting up and configuring perfmon graphs can be time consuming so you can save them as counter logs, however you can also save a graph as html which will produce an html page with an embedded perfmon graph complete with all your counters and configurations. You can just open this page in your browser to start monitoring. This also means you can build and keep or publish a library of useful graphs.
</gotchas>
Advertisements

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: