What is the overhead in using a .NET Service Reference to call a web service?

Question

I am consuming a web service from a third party. I am measuring the time it takes to call a web method and timing the network traffic. I am finding that the call takes considerably longer than the network traffic does.

I ran the app and used fiddler to watch the traffic and it takes 46ms to open the HTTP CONNECT Tunnel and 951ms to send the data. I would expect this total to be about 1000ms, however it is coming out at 1504ms. 500ms may not seem like much but this was done from a test server, from the live servers we are regularly seeing response times of 6 seconds, for a network call which takes 1 second.

This is the code I am using to measure the time of the web method call

  Dim service As New SupplementaryEnquiryV1PortTypeClient()

    Dim _stopWatch As New Stopwatch()

    _stopWatch.Start()

    response = service.Enquiry(request)

    _stopWatch.Stop()

The client is written in VB .NET, Framework version 4.5

The client was generated by adding a service reference in visual studio, I have also tried using svcutil.exe to generate the service reference.

I believe the web service is written in Java, but I have no access to the code. The service returns data about a single vehicle which I assume is pulled from a database.

I've tried using a service end point which was not using SSL, which made no difference.

I've tried setting the CacheSetting property on System.ServiceModel.ClientBase(Of T) to AlwaysOff and AlwaysOn and neither made any difference. I've also tried setting "Generate serialization assemblies" to On for the project.

I've used traceroute to check for any network related problems.

From Fiddler:

CONNECT uat-wss.xxx.co.uk:443 HTTP/1.1

ClientConnected: 15:23:20.011
ClientBeginRequest: 15:23:20.027
GotRequestHeaders: 15:23:20.027
ClientDoneRequest: 15:23:20.027
Determine Gateway: 0ms
DNS Lookup: 29ms
TCP/IP Connect: 18ms
HTTPS Handshake: 20ms
ServerConnected: 15:23:20.074
FiddlerBeginRequest: 15:23:20.074
ServerGotRequest: 15:23:20.074
ServerBeginResponse: 00:00:00.000
GotResponseHeaders: 00:00:00.000
ServerDoneResponse: 00:00:00.000
ClientBeginResponse: 15:23:20.074
ClientDoneResponse: 15:23:20.074

Overall Elapsed: 0:00:00.046

POST /TradeSoap/services/SupplementaryEnquiryV1/ HTTP/1.1

ClientConnected: 15:23:20.011
ClientBeginRequest: 15:23:20.105
GotRequestHeaders: 15:23:20.105
ClientDoneRequest: 15:23:20.464
Determine Gateway: 0ms
DNS Lookup: 0ms
TCP/IP Connect: 0ms
HTTPS Handshake: 0ms
ServerConnected: 15:23:20.074
FiddlerBeginRequest: 15:23:20.464
ServerGotRequest: 15:23:20.464
ServerBeginResponse: 15:23:20.479
GotResponseHeaders: 15:23:20.994
ServerDoneResponse: 15:23:21.041
ClientBeginResponse: 15:23:21.041
ClientDoneResponse: 15:23:21.057

Overall Elapsed: 0:00:00.951

Edit

As suggested by usr I have put the code through a profiler. I have used the built in one in 2012 (see below). It looks like Microsoft.Xml.Serialization.ArrayOfObjectsSerializer1.Deserialize is taking up a lot of time. What could cause this to take several seconds?

Answer 1

You might be witnessing the the effects of the Nagle Algorithm, try:

this.webRequest.UseNagleAlgorithm.ServicePoint = false;

Also, the Expect100Continue 'handshake' is relevant to soap service call performance:

this.webRequest.Expect100Continue.ServicePoint = false;

Nagle will withhold sending of network packets for a short time in an effort to try and send fewer but larger data packets. Using this is perhaps a matter of etiquette when communicating over the public internet. Do your own research.

Expect100Continue will prevent the SOAP request XML being sent on the initial HTTP PUT/POST, the server will send an OK/CONTINUE and the client will then send the SOAP request XML. This additional handshaking (two full roundtrips intsead of one) will also introduce a delay.