Ayende @ Rahien

Unnatural acts on source code

A WCF Perf Mystery

Anyone can tell me why this is taking a tad over 11 seconds?

   1: class Program
   2: {
   3:     static void Main(string[] args)
   4:     {
   5:         try
   6:         {
   7:             var sw = Stopwatch.StartNew();
   8:             var host = new ServiceHost(new Srv(), new Uri("net.tcp://localhost:5123"));
   9:             host.AddServiceEndpoint(typeof (ISrv), new NetTcpBinding(), new Uri("net.tcp://localhost:5123"));
  10:             host.Open();
  11:  
  12:             var srv = ChannelFactory<ISrv>.CreateChannel(new NetTcpBinding(),
  13:                                                              new EndpointAddress(new Uri("net.tcp://localhost:5123")));
  14:             srv.Test("hello"); // if I remove this, it finishes in 0.3s - 0.5s
  15:  
  16:             host.Close();
  17:  
  18:             Console.WriteLine(sw.Elapsed);
  19:         }
  20:         catch (Exception e)
  21:         {
  22:             Console.WriteLine(e);
  23:         }
  24:     }
  25: }
  26:  
  27: [ServiceContract]
  28: public interface ISrv
  29: {
  30:     [OperationContract]
  31:     int Test(string x);
  32: }
  33:  
  34: [ServiceBehavior(InstanceContextMode = InstanceContextMode.Single, ConcurrencyMode = ConcurrencyMode.Multiple)]
  35: public class Srv : ISrv
  36: {
  37:     public int Test(string x)
  38:     {
  39:         return x.GetHashCode();
  40:     }
  41: }

The reason that I care is that I am doing that in my tests, and this is significantly slow them down.

Is there anything that I am missing?

Comments

Set
02/07/2009 05:54 AM by
Set

It's the first call...So I guess everything gets initialized at that moment

Cos
02/07/2009 06:06 AM by
Cos

According to the profiler, it's the close() that takes up your time.

Steve
02/07/2009 06:15 AM by
Steve

Network?

James Kovacs
02/07/2009 06:52 AM by
James Kovacs

Your client, srv, has an open TCP connection to the host. When you say:

host.Close();

there is a default 10 second timeout for the client to finish communication. (Total time on my machine is 11.15 s.) You know that communication is finished. So explicitly specify the timeout:

host.Close(new TimeSpan(0));

Completion time is 1.14s with this change.

Or you can close the client channel after the call to srv.Test():

var clientChannel = (IChannel)srv;

clientChannel.Close();

Completion time is also 1.14s.

HTH, James

Mark Monster
02/07/2009 11:48 AM by
Mark Monster

That's interesting information James. This is good to know, I always thought that the starting of a ServiceHost took so much time.

Mark Monster

Ben C
02/09/2009 02:00 AM by
Ben C

Hi Ayende, The line numbers in the code snippet come out when you cut and paste. So in order to run the snippet one must remove them by hand. On some blogs you get a link to copy the plain code to the clipboard. Actually, I don't think the line numbers are necessary, as you don't refer to them at all. Cheers.

Dave
02/09/2009 08:04 AM by
Dave

I believe that WCF is using some sort of on demand (lazy) initialization. On line 12 a proxy between ISvr and Svr (the class, not the var) is created and used as a client. If it's the first call towards WCF than most of the WCF framework is loaded. It's works a bit like how applications are created and destroyed in the asp.net process. The first visitors initializes the application and is faced a longer execution time than following requests.

I also noticed on our services that it once occurred once. So during the startup of our service master host (a windows service that fires up other WCF services), after the host is created, we perform the first call, so the framework is loaded and clients don't have to deal with a slow first call.

I can't backup most of the stories and mainly believed that we we're using WCF somehow in a wrong way. Because we had a simple workaround we didn't put that much attention to it. Now, after reading this post, I'm getting seconds doubts..

magellings
02/09/2009 04:39 PM by
magellings

If it's the first call it will take a while as it's a cold startup for WCF. Be sure to have 3.5 SP1 installed on the machine. Optimization was done to the CLR to improve cold startup times.

Luc
02/11/2009 04:13 PM by
Luc

Don(t forget to close the proxy. It will allow for the TCP connection to be closed without timeout when you call Host.Close().

Just add:

((IDisposable)(srv)).Dispose();

after srv.Test("hello");

Comments have been closed on this topic.