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
basicHttpBindingto 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>