Why is the first WCF client call slow?

.net, .net-4.0, basichttpbinding, performance, wcf

Solution

Usually the first call takes more time because in that call the `Channel Factory` is instantiated and prepared ready for the communication and that costs time. The created `Channel Factory` will be cached and reused in subsequent calls and so the time will be less.

http://social.msdn.microsoft.com/Forums/en/wcf/thread/43f89088-546b-46b0-adf8-214deb1741bd

Problem

I am trying to figure out why the first WCF call after client application start takes much more time comparing to second one. What I did to test that: - Implemented simple self hosted WCF Server and console client. - Server IS warmed up - I run it and call method several times before running test. - Binding is `basicHttpBinding` to reduce network and security overhead. - Testing scenario - start console client app, making two identical WCF service calls in a row. In my tests I see ~700 milliseconds for first call and ~3 milliseconds for second call. Almost a second seems to be too much time for JIT compiler. I would accept if that time is used to initialize some complicated infrastructure like `ObjectContext` in Entity Framework but my code is very simple and proxy classes are already compiled. I also tried `netNamedPipeBinding` binding. Result proves pattern - first call takes ~800 ms, second call takes ~8 ms. Will appreciate if anybody can explain why the first service call takes so much time. Tested in Win 7 64 bit. My implementation is below. Contract: ``` [ServiceContract] public interface ICounter { [OperationContract] int Add(int num); } ``` Service Implementation: ``` public class CounterService: ICounter { private int _value = 0; public int Add(int num) { _value += num; Console.WriteLine("Method Add called with argument {0}. Method returned {1}", num, _value); return _value; } } ``` Server Implementation: ``` class Program { static void Main(string[] args) { Uri baseAddress = new Uri("http://localhost:8080/Service"); // Create the ServiceHost. using (ServiceHost host = new ServiceHost(typeof(CounterService), baseAddress)) { host.Open(); Console.WriteLine("The service is ready at {0}", baseAddress); Console.WriteLine("Press <Enter> to stop the service."); Console.ReadLine(); // Close the ServiceHost. host.Close(); } } } ``` Server Configuration: ``` <?xml version="1.0" encoding="utf-8" ?> <configuration> <system.serviceModel> <services> <service name="Server.CounterService"> <endpoint address="base" binding="basicHttpBinding" name="baseDefault" contract="Contract.ICounter" /> <endpoint address="net.pipe://localhost/Service/netNamedPipe" binding="netNamedPipeBinding" name="netNamedPipeDefault" contract="Contract.ICounter" /> <endpoint address="mex" binding="mexHttpBinding" contract="IMetadataExchange" /> </service> </services> <behaviors> <serviceBehaviors> <behavior name=""> <serviceMetadata httpGetEnabled="true" /> </behavior> </serviceBehaviors> </behaviors> </system.serviceModel> </configuration> ``` Client Implementation (`CounterProxy` is generated from service reference): ``` Stopwatch stopWatch = new Stopwatch(); stopWatch.Start(); using (var proxy = new CounterProxy.CounterClient(_endpointConfigurationName)) { output = proxy.Add(1); } stopWatch.Stop(); // Get the elapsed time as a TimeSpan value. TimeSpan ts = stopWatch.Elapsed; ``` Function that contains that code called two times in a row. Client Configuration: ``` <?xml version="1.0" encoding="utf-8" ?> <configuration> <system.serviceModel> <client> <endpoint address="http://localhost:8080/Service/base" binding="basicHttpBinding" contract="CounterProxy.ICounter" name="baseDefault" /> </client> </system.serviceModel> </configuration> ```

Original source