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>

Answer 1

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).

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

Answer 3

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

Answer 4

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