Jaa


Why Does WCF Become Slow After Being Idle For 15 Seconds?

Customers reported the following WCF performance issue recently:

· A WCF service over TCP or Named Pipe idles for over 15 seconds and the first request after that becomes very slow. Why?

This can be easily reproduced. Basically, if you send two consecutive requests to a WCF service over TCP or Named Pipe transport, you would see something as following:

First message invocation:

Latency for thread 0: 0.0758616 seconds

Sleep for 16 ms

Latency for thread 0: 0.0030432 seconds

However, if it sleeps for 15 seconds, you would get:

First message invocation:

Latency for thread 0: 0.0774229 seconds

Sleep for 15000 ms

Latency for thread 0: 0.4179955 seconds

Here it takes about 418 milliseconds to complete the second request. Sometimes this delay can be even longer. Why does this happen?

The main reason for this is that the CLR ThreadPool has a 15-second timeout for idle threads. It releases all of the I/O threads except for one so that this last one can process I/O requests immediately. If this last I/O thread is used somehow, the ThreadPool would take time to create new threads to handle new WCF requests and also introduced random delays when creating a new thread, even if the number of active threads is smaller than the MinIOthreads setting (can be set through ThreadPool.SetMinThreads). This is a known CLR issue and it is unfortunately that it is still not fixed in 4.0. For WCF services over TCP or Named Pipe, however, WCF does hold one I/O thread to manage timers for the sessionful channels internally. If you attached the debugger to the service, you would see the following active I/O thread:

0:009> !clrstack

OS Thread Id: 0x1b90 (9)

Child-SP RetAddr Call Site

000000001c3aedc0 000007fef4e0c29c System.Threading.WaitHandle.WaitAny(System.Threading.WaitHandle[], Int32, Boolean)

000000001c3aee20 000007fef4d9713a System.ServiceModel.Channels.IOThreadTimer+TimerManager.OnWaitCallback(System.Object)

000000001c3aee80 000007fef73395a9 System.ServiceModel.Channels.IOThreadScheduler+CriticalHelper+WorkItem.Invoke2()

000000001c3aef00 000007fef4d9708f System.Security.SecurityContext.Run(System.Security.SecurityContext, System.Threading.ContextCallback, System.Object)

000000001c3aef40 000007fef4d96fb0 System.ServiceModel.Channels.IOThreadScheduler+CriticalHelper+WorkItem.Invoke()

000000001c3aef90 000007fef4d96e32 System.ServiceModel.Channels.IOThreadScheduler+CriticalHelper.ProcessCallbacks()

000000001c3af000 000007fef4d96dc1 System.ServiceModel.Channels.IOThreadScheduler+CriticalHelper.CompletionCallback(System.Object)

000000001c3af050 000007fef8028815 System.ServiceModel.Channels.IOThreadScheduler+CriticalHelper+ScheduledOverlapped.IOCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)

000000001c3af080 000007fef730a71e System.ServiceModel.Diagnostics.Utility+IOCompletionThunk.UnhandledExceptionFrame(UInt32, UInt32, System.Threading.NativeOverlapped*)

000000001c3af0e0 000007fef8e1d502 System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32, UInt32, System.Threading.NativeOverlapped*)

Fortunately there is a workaround for this issue, as provided by Eric Eilebrecht. Basically you need to keep another I/O thread idle so that it won’t get timed out (in a 15-second internal). It is not ideal but it solves the problem. You can add the following code to the WCF service side:

    static class ThreadPoolTimeoutWorkaround

    {

        static ManualResetEvent s_dummyEvent;

        static RegisteredWaitHandle s_registeredWait;

        public static void DoWorkaround()

        {

            // Create an event that is never set

            s_dummyEvent = new ManualResetEvent(false);

            // Register a wait for the event, with a periodic timeout. This causes callbacks

            // to be queued to an IOCP thread, keeping it alive

            s_registeredWait = ThreadPool.RegisterWaitForSingleObject(

                s_dummyEvent,

                (a, b) => {

                    // Do nothing

                },

                null,

                1000,

                false);

        }

    }

Now you can invoke the above workaround method anywhere in your code:

            ThreadPoolTimeoutWorkaround.DoWorkaround();

This workaround uses a wait thread to wait for an event which is never set. When the thread times out (in one second), it queues up a packet to the IOCompletionPort. The packet does nothing but causes the IOCompletionPort to wake up and thus keeps the I/O thread from being timed out (with 15 seconds timeout as mentioned above). Since this is a repeating wait that will always time out, we’ll keep queueing packets to the IOCP, and keep at least one thread alive forever. As long as a single I/O thread stays “free” in this manner, a new I/O thread would be created quickly. Note that for .NET 3.5, you also need the QFE that I mentioned in my previous blog entry to be installed.

With this workaround, you would notice the following result:

First message invocation:

Latency for thread 0: 0.0300781 seconds

Sleep for 15000 ms

Latency for thread 0: 0.0032901 seconds

The sample code is attached.

WcfIdleSlowness.zip

Comments

  • Anonymous
    February 10, 2010
    Will this be addressed in a future service pack or something?  Hope we don't have to resort to these types of workarounds for another two years while we wait for next release of the framework.

  • Anonymous
    February 12, 2010
    Yes, this will be fixed in the next release. We found this late and was not able to get it addressed in .NET 4.0.

  • Anonymous
    February 17, 2010
    Hi Wenlong, Will this be fixed in next SP/hotfix or the next release of framework? Thanks, Akshat

  • Anonymous
    May 15, 2010
    I thought it was normal (as described somewhere in the MSDN). Thanks Ashraf Thoppukadavil.

  • Anonymous
    May 16, 2010
    how do i call ThreadPoolTimeoutWorkaround if I host under WAS (IIS 7). any alternative solution than this? http://blogs.msdn.com/wenlong/archive/2006/01/11/511514.aspx

  • Anonymous
    October 05, 2010
    This does not work for me. And it seems resonable. RegisterWaitForSingleObject uses worker threads and not IO. Right?

  • Anonymous
    October 05, 2010
    Sorry, it does work! The problem for me is that I need to keep alive 300 threads, since I'm waiting for 300 requests. Another problem is that if this code runs while requests are in progress (meaning that 300 threads are already open), it will open another 300 threads increasing the number of threads to 600.

  • Anonymous
    February 08, 2011
    Dimitri, are you calling the DoWorkaround() in the constructor ? Better create an additional static bool where you can check if it's not already started for this WCF Service !

  • Anonymous
    July 18, 2011
    Beware when implementing this workaround. Just debugged a related issue on a project: the workaround was call in the service's constructor, and the service had the InstanceContextMode property of the ServiceBehavior attribute set to InstanceContextMode.PerCall. So every time a call to the service was made, the workaround was executed, and a new thread was created with the 1 second timeout. That's already bad, but it was even worse since there was many calls by seconds made to this service, thus leaking threads until reaching the limit set in the ThreadPool. Then the service couldn't be instantiated anymore, and the process became unresponsive.

  • Anonymous
    July 29, 2011
    KooKiz, did you really notice the thread leaking? I did not see it in my local test.

  • Anonymous
    September 16, 2011
    Do you know if it will be fixed on .NET 4.5 ?

  • Anonymous
    August 28, 2012
    One question, is this problem resolved in Framework 4.5?? Is very important for my project: blogs.msdn.com/.../why-does-wcf-become-slow-after-being-idle-for-15-seconds.aspx Thanks!

  • Anonymous
    August 30, 2012
    This is fixed in .NET 4.5.

  • Anonymous
    August 30, 2012
    Yes, it is fixed in Framework 4.0.3 too, you only have to increase the minumun number of threads, something like this: ThreadPool.SetMinThreads(50,50); Thanks!!