Analyzing why WCF much slower than WSE webservice

Question

We have a web service with both WSE 3.0 endpoints and the newer WCF endpoints on .NET Framework 4.5.

WCF is using basicHttpBinding.

The problem is that the new WCF bindings appear to be significantly slower (~3x). Does it use the same mechanism under the hood?

I've read a lot about enabling WCF tracing. But when I enable that on production I get way to much information and don't really know how read e.g. the timeline in Microsoft Trace Viewer.

I would appreciate any help

• Tips for finding causes of the performance difference
• Idea from a theoretical standpoint, e.g. are there any major differences under the hood in how WCF processes a request?
• Any tools that can help to profile WCF server

Notes:

• The issue exists in production; on the test servers everything goes fine. At first we suspected that the load balancer might be a factor, but disabling the load balancer does not change the performance at all

• The slowness could be due our application/domain layer of course. Maybe some thread/connection pool is blocking and messages are getting queued because of that.

  In this case does anyone have an idea why the behaviour is so different from WSE (which runs on the same application pool)? Did any queue sizes/concurrent processing default configurations change dramatically between WSE3.0 and WCF?

  Is there a way to find out when this is happening? E.g. some perfmon counters to watch? In perfmon I just get lost choosing between the huge amount of performance counters available

Update

Here's an anonymized version of our service Web.config:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
    <configSections>
        <section name="microsoft.web.services2" type="Microsoft.Web.Services2.Configuration.WebServicesConfiguration, Microsoft.Web.Services2, Version=2.0.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" />
        <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
    </configSections>
    <system.web>
        <httpRuntime executionTimeout="900" maxRequestLength="10240" />
        <webServices>
            <!--<wsdlHelpGenerator href="CustomizedWebServicePage.aspx" />-->
            <protocols>
                <add name="HttpGet" />
                <add name="HttpPost" />
            </protocols>
            <soapExtensionTypes>
                <add type="Microsoft.Web.Services2.WebServicesExtension, Microsoft.Web.Services2, Version=2.0.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" priority="1" group="0" />
            </soapExtensionTypes>
        </webServices>
        <compilation defaultLanguage="cs" debug="true" targetFramework="4.5" />
        <customErrors mode="RemoteOnly" />
        <!-- dev only - application pool identity is configured on real environment -->
        <identity impersonate="true" userName="ServiceIdentity" password="********" />
        <authentication mode="Windows" />
        <authorization>
            <allow users="*" />
            <!-- Allow all users -->
        </authorization>
        <trace enabled="false" requestLimit="10" pageOutput="false" traceMode="SortByTime" localOnly="true" />
        <sessionState mode="InProc" cookieless="false" timeout="20" sqlConnectionString="data source=127.0.0.1;user id=someuserid;password=********;port=42424" />
        <globalization requestEncoding="utf-8" responseEncoding="utf-8" />
        <pages controlRenderingCompatibilityVersion="3.5" clientIDMode="AutoID" />
    </system.web>
    <microsoft.web.services2>
        <diagnostics>
            <detailedErrors enabled="true" />
        </diagnostics>
        <policy>
            <cache name="policyCache.xml" />
        </policy>
        <security>
            <timeToleranceInSeconds>43200</timeToleranceInSeconds>
            <defaultTtlInSeconds>43200</defaultTtlInSeconds>
            <x509 storeLocation="LocalMachine" verifyTrust="false" />
            <securityTokenManager type="OurProduct.Business.Authentication.CustomUsernameTokenManager, OurProduct.Business, Version=5.0.2.11517, Culture=neutral" qname="wsse:UsernameToken" xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd" />
        </security>
        <messaging>
            <maxRequestLength>10240</maxRequestLength>
        </messaging>
    </microsoft.web.services2>
    <startup>
        <supportedRuntime version="v2.0.50727" />
    </startup>
    <system.serviceModel>
        <diagnostics wmiProviderEnabled="true">
            <messageLogging logMalformedMessages="true" logMessagesAtTransportLevel="true" />
        </diagnostics>
        <serviceHostingEnvironment aspNetCompatibilityEnabled="true" multipleSiteBindingsEnabled="true" />
        <services>
            <service behaviorConfiguration="OurServiceBehavior" name="OurProduct.Service.OurService">
                <endpoint address=""      binding="basicHttpBinding"  bindingConfiguration="BasicHttpBinding_IXXXOurService" bindingNamespace="http://localhost/XXXOurService" contract="OurProduct.ServiceContracts.XXXOurService.IXXXOurService" />
            </service>
        </services>
        <behaviors>
            <serviceBehaviors>
                <behavior name="OurServiceBehavior">
                    <dataContractSerializer maxItemsInObjectGraph="2147483647" />
                    <serviceMetadata httpGetEnabled="false" httpsGetEnabled="true" />
                    <serviceDebug includeExceptionDetailInFaults="true" />
                    <serviceCredentials>
                        <userNameAuthentication userNamePasswordValidationMode="Custom" customUserNamePasswordValidatorType="OurProduct.Service.Validation.CustomUserNamePasswordValidator, OurProduct.Service" />
                    </serviceCredentials>
                </behavior>
                <behavior name="">
                    <serviceMetadata httpGetEnabled="true" httpsGetEnabled="true" />
                    <serviceDebug includeExceptionDetailInFaults="false" />
                </behavior>
            </serviceBehaviors>
        </behaviors>
        <bindings>
            <basicHttpBinding>
                <binding name="BasicHttpBinding_IXXXOurService" closeTimeout="00:01:00" openTimeout="00:01:00" receiveTimeout="00:15:00" sendTimeout="00:15:00" bypassProxyOnLocal="false" hostNameComparisonMode="StrongWildcard" maxBufferPoolSize="524288000" maxBufferSize="524288000" transferMode="Buffered" maxReceivedMessageSize="524288000" messageEncoding="Mtom" textEncoding="utf-8" useDefaultWebProxy="true" allowCookies="false">
                    <readerQuotas maxDepth="524288000" maxStringContentLength="524288000" maxArrayLength="524288000" maxBytesPerRead="524288000" maxNameTableCharCount="524288000" />
                    <security mode="TransportWithMessageCredential">
                        <transport clientCredentialType="None"     />
                        <message   clientCredentialType="UserName" />
                    </security>
                </binding>
            </basicHttpBinding>
        </bindings>
    </system.serviceModel>
    <runtime>
        <gcServer     enabled="true" />
        <gcConcurrent enabled="true" />
    </runtime>
    <system.webServer>
        <security>
            <requestFiltering>
                <requestLimits maxAllowedContentLength="10485761" /> <!-- 10 megabytes -->
            </requestFiltering>
        </security>
    </system.webServer>
</configuration>

Val

Microsoft claims it is 4 times faster because of the use of XmlDocument vs XmlReader: msdn.microsoft.com/en-us/library/…. It seems a case you do something like filtering of in your binding that is bad for your WCF performance. Can you post your bindings and what attributes do you have on your service methods? – Banzai

@peer, here are the bindings (anonymized): pastebin.com/VKhxEqbQ – Val

You have custom OurProduct.Business.Authentication.CustomUsernameTokenManager and OurProduct.Service.Validation.CustomUserNamePasswordValidator classes for security. Did you test the performance difference without them to be sure the OurProduct.Service.Validation.CustomUserNamePasswordValidator implementation is not the problem. – Banzai

It's hard to test this because issue only reproduced in production environment (not reproduced for testing or dev. computers) and this fact also makes me feel that this settings make no difference here otherwise the issue would be reproducible everywhere – Val

Answer 1

Your WCF service configuration file does not appear to have throttling values explicitly set. You may want to use performance monitor to track the WCF resources and/or adjust the default values to make sure you are not hitting the default throttle limit.

Service throttling (serviceThrottling) allows you to even out the load on your backend WCF servers and to enforce resource allocation. serviceThrottling behavior for backend WCF services is configured by modifying the values for the maxConcurrentCalls, maxConcurrentSessions, and maxConcurrentInstances parameters in the config file for the WCF service.

<serviceThrottling
maxConcurrentCalls="200"
maxConcurrentSessions="200"
maxConcurrentInstances="200" />

https://msdn.microsoft.com/en-us/library/ee377061%28v=bts.70%29.aspx

Phosphaturia

Since the problem appeared we tried to play with these settings (serviceThrottling), and tried even huge numbers like maxConcurrentCalls="100000" but it did not make any difference – Val

can you provide your InstanceContextMode and ConcurrencyMode property settings? – Phosphaturia

InstanceContextMode = InstanceContextMode.PerCall, ConcurrencyMode = ConcurrencyMode.Single – Val

The following article outlines some helpful considerations, 1. Ensure the service has enough IO threads in the ThreadPool (setMinThreads) 2. Ensure the service class constructor is efficient (i.e. no expensive initialization ) theburningmonk.com/2010/05/… – Phosphaturia

@Phosphaturia especially with this last comment, your answer has been a treasure trove of knowledge. I'll leave it to the OP to accept an answer (some time in the future). But at this point I wish to award the bounty to you. Thanks for sharing your knowledge – Proof

Answer 2

Using WCF diagnostics is great, but as far as I know you won't be able to get similar diagnostics from the Web Service so you won't have anything to compare against. However the diagnostics you are preparing in your answer will give you an indication of relative time spent in each phase of the service call.

I'll propose an alterative which should be very simple because you're using http / text in both cases. Just catch both of the responses using Fiddler or your favorite proxy tool and compare. And critically - make sure that you look at the http header, not just the body. Fiddler will tell you the round trip time and the size of the response, which should be enough.

What could this be? The obvious things:

• I've experienced huge performance overhead (yes, around 3x) when using Windows Authentication with WCF. I've seen the message size blow out when using Windows Authentication due to a large encrypted blob in the header (from memory). This costs a lot of time in transmission alone.
• Also on security, is the WCF request being encrypted? If you use message security then it will be packed on the server side and unpacked on the client side. This is also not free.
• Multiple service instances. You should have your service set for multiple instances, which means that each operation will create its own service instance. This is the default behavior. Configured as an attribute on the service class itself, like [System.ServiceModel.ServiceBehavior(ConcurrencyMode = System.ServiceModel.ConcurrencyMode.Multiple)]

You are correct in that there are many performance counters for WCF. They are grouped by service, endpoint and operation. You probably want the service counters, as they have more information. Check the ServiceModelService 4.0 category, and look at

• Calls (obviously)
• Calls Per Second
• Instances
• Instances Created Per Second

Chartreuse

We're using transport level security only. Messages are not encrypted. – Val

ConcurrencyMode is Single at the moment, we're looking into our options to change that now. – Val

ConcurrencyMode = System.ServiceModel.ConcurrencyMode.Multiple tried this way and did not make any difference – Val

Answer 3

I would suggest to debug this in the following way:

1. temporarily remove all authentication and security logic from both services and see if the problem remains

2. temporarily disable any business logic and possibly simplify the schema to a single variable

3. when you say performance is slower, do you mean a single user performance or a load test? when you check a single user do you make sure the server is warm?

4. if you time the execution duration of your logic (e.g. from start to end of the your server method implementation) - is it the same?

5. remember to cancel any logging / tracing while benchmarking

6. you can try to revert wcf to use XmlSerializer instead of DataContract

Frank

1 - this is not possible so far as server and clients are already in production 2 - also not possible for now 3 - reproduces stably for any client application 4 - 90% sure that time is the same 5 - true 6 - also hard to try due to this is all in production but we need to consider this – Val

Answer 4

Sorry for answering in answer,I dont have enough reputation for comments. Which specific informations (traces) you would like to see? If you have difficulties setting up tracing, I would recommend you using tool named SvcConfigEditor.exe. In it, you can open App.Config file of your WCF service and under "Diagnostics", you can enable tracing. After that, you can select whether you want to trace particular information - so called "Trace level" (more infromation about specific levels - Configuring tracing ). See screenshot of the tool:

After you trace required information, you can open the log in Microsoft Trace Viewer - in it, you can view time duration of each acitvity: For example consider this one (sorry - some labels are in Czech language):

Sorry, picture was unreadable, here is link to bigger one : Trace viewer

On the left, you can select particular activity - if you stretch the panel, you can even see start and end time. Also, you see the total duration of that activity. After you select it, in the top-left panel you can see all the calls, that belong to that activity and you can also see, which call took the most time to resolve (In "Time" column).

Tletski

Thanks for a reply, is there a way I can trace messages only from one client computer? I mean add tracing on server but I'm only interested in one client computer that I research problem now – Val

Hmmm, my guess would be to start tracing on client side, rather than on server side. Simply turn off (remove) tracing from service app.config and set it up in client´s app.config. This discussion suggest it can be done: social.msdn.microsoft.com/Forums/vstudio/en-US/… – Tletski

Thanks for advise. From client side logs I don't see anything interesting I execute one method 100 times and can see that sometimes it's executed within 1 sec and sometimes ~10 seconds, that's all what I see, but I would like to get more info from server side of what's the difference between these 2 calls – Val

Well Trace Viewer wont tell you,why specific method call lasted longer than the previous one, thats true.If you need detailed inspection of each method, you can use Performance and Diagnostics tool (in VS, under tab Analyze) and run specific test.I havent done much with that tool though,so I dont know the details - but for example if I run CPU consumption test and then create detailed report, I can see which step in method took some time: postimg.org/image/njtzct6hb/full .But of course you cant filter to one client only, since the performance is run on service-side – Tletski

Unfortunately I don't have visual studio on the server as this is all production, so will be researching anyway thanks for help – Val

Oh ok.You are welcome...maybe someone else will post an answer with some nice Diagnostic tool that will be able to help you :). – Tletski