Tuesday, May 15, 2007

IIS based Web Service - Delayed Response

After a long break updating my blog, I'm back.
I had some interesting issues in the last few month and I hope I'll have the time posting them here....

I'll begin with the oldest one.
Few months back one of the developers in the development team was complaining about a very slow response times from a web service he developed and was running in our Test environment.
He told me that the problem only occurs in the first request, or on the first request after long time (30 mins or above), but he cannot be exact and can't reproduce it.
The normal response time is about 1-2 seconds but to the first one, which takes almost 30!
He also told me that there is nothing 'heavy' or complex in the initialization process and he suspects that the problem is in IIS or the CLR...

I followed his directions and the first thing came in my mind is the "Idle timeout" that can be configured to IIS Application Pools. Surprisingly it was actually configured to 20 mins! I turned it off (to never shutdown an idle application pool).

After couple of hours he came back complaining that the problem still occurs.
My next step was to look for some ASP.NET configuration options in web.config and machine.config but I found nothing really related...

I had no direction and the only thing in my mind was that maybe something is wrong with the server(IIS or .NET Framewok), so I set up a virtual server with other OS version(Wndows 2003 Web Edition) and tried causing the problem to appear again.

I noticed that the only way to reproduce the behavior was to boot the server - Killing the worker process or restarting the IIS didn't trigger it.

Now with the option to reproduce in my hands, I could really start digging. I started (Microsoft's) System Internals' Process Explorer and watched the w3wp.exe of the WebService (w3wp.exe is the instance of the "Application Pool" you see in IIS). I checked to see if it was working and using CPU and not just waiting or hang on something. I drilled down to its threads tring to detect where the problem is. If the problem was in his code I could see it, but it was happening very long time before his code was invoked. I saw some threads waiting on a method named CompareAssemblyIdentity (a method used to "compares two assembly identities to determine whether they are equivalent"). Few moments later I noticed some new child processes running under the worker process, named csc.exe (C# Compiler) and they (in their turn) created another process as well !! Only then I realized the problem! ASP.NET is Recompiling the classes for the first time the Web Service is used! It is that simple.

Boot is not the only trigger for ASP.NET recompilation and it wasn't the case of the poor developer as well. The other trigger is much more relevant to his case - changes in the code. He just forget telling me he was still working on it and publishing his code relative frequently to the test server...