WCF calling webservice taking a long time

Question

I have a wcf service (WCF_A ) which calls another wcf service (WCF_B) (currently I am hosting the WCF_B on my local machine with my credentials – as windows service), WCF_B internally makes a call to a webservice (WS01) that is hosted on the IIS. I have created a test client and call the WCF_A -> WCF_B -> WS01. Just before making the call to (WS01) I start a timer and I stop the timer when the webservice call comes back and the result is assigned to a variable, the flow is as below WCF_B

1)  Debug.WriteLine(“Call to webservice”)
2)  Starttimer
3)  Var result = WS01.Function(xxxx)
4)  Stop timer
5)  Debug.Writeline (timetaken)
6)  Debug.WriteLine(“Call from webservice came back”)

The very first time I make the webservice function call I find that between step (2) and step (5) it takes a really long time.

My initial thought was that the proxy creation is taking a long time, running Fiddler I find that the call to the webservice is made and comes back with the expected results instantly.

After that I am not sure what happens and the process seems to wait. (It takes almost close to 2.5 minutes to hit step (5).

Once the call is made if I turn around and make the same call with different parameters to the webservice the step (5) is hit in around 1.1 sec (Time Taken). I am not sure what is going on here. It almost appears that in step (3) the assignment to result variable is taking a lot of time but not sure why this happens only the first time.

I have a also created a Test Client and call WCF_B directly (hosted using wcf provided WCFHost) although the call does not take a long time as the previous case it comes back in 9.8 secs the first time and around 1 sec after that again the call seem to be waiting during the assignment.

Any pointers on identifying what is going on?

Thanks for your help

Answer 1

My first guess would be that the first call is slower because of the .NET infrastructure itself. Your WCF are compiled into an intermediary language by the C# ou VB.NET compiler. At runtime, this code is compiled into native code to be executed by the system. This is called Just-In-Time compilation and occurs once for each method the first time it is executed in your application.

So unless, you are able to reproduce the behavior you describe on the 2nd, 3rd or Nth call to the service, I think it is safe to assume it is just expected behavior.

1. You can also use a profiler to trace what exactly is taking a long time to execute.
2. If you expect WCF to be the source of the problem, enable activity tracing on the WCF client and see if you can spot the delay in the list of activities traced.