Windows – Timer_EntityBody, Timer_ConnectionIdle and Connection Closed Unexpectly

httpiis-7.5web serviceswindowswindows-server-2008

We have a windows application, it connects to a web service (XML web service hosted on a Windows 2008 Server IIS 7.5, no antivirus) and fetches some data to the client. But sometimes (around 5%-10% of the requests), it gives an error when trying to connect web service.

Here is the client application error log;

Exception:System.Net.WebException: The underlying connection was closed: The connection was closed unexpectedly.
at System.Web.Services.Protocols.WebClientAsyncResult.WaitForResponse()
at System.Web.Services.Protocols.WebClientProtocol.EndSend(IAsyncResult asyncResult, Object& internalAsyncState, Stream& responseStream)
at System.Web.Services.Protocols.SoapHttpClientProtocol.EndInvoke(IAsyncResult asyncResult)
at APPClient.APPFPService.WEBService.EndAddMoney(IAsyncResult asyncResult)
at APPClient.BLL.ServiceAgent.AddMoneyCallback(IAsyncResult ar)

From other hand, on the web server, i checked HTTP error logs and i see a long file like this;

2014-06-05 14:02:04 65.82.178.73 53798 SERVER.IP.ADDRESS 80 - - - - - Timer_ConnectionIdle -
2014-06-05 14:07:24 76.109.81.223 58985 SERVER.IP.ADDRESS 80 - - - - - Timer_ConnectionIdle -
2014-06-05 14:07:39 76.109.81.223 2803 SERVER.IP.ADDRESS 80 - - - - - Timer_ConnectionIdle -
2014-06-05 14:08:59 76.109.81.223 52656 SERVER.IP.ADDRESS 80 - - - - - Timer_ConnectionIdle -
2014-06-05 14:09:05 65.82.178.73 53904 SERVER.IP.ADDRESS 80 HTTP/1.1 POST /webservice/webservice.asmx - 2 Timer_EntityBody SYPService
2014-06-05 14:10:55 50.186.180.191 50648 SERVER.IP.ADDRESS 80 - - - - - Timer_ConnectionIdle -

Here is a similar situation but it did not help me.

UPDATE:
When i checked the IIS logs, i see some issues like these;

cs-method   cs-uri-stem                     sc-status   sc-win32-status     time-taken  cs-version
POST        /webservice/webservice.asmx     400         64                  46          HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  134675      HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  37549       HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  109         HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  31          HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  0           HTTP/1.1
POST        /webservice/webservice.asmx     400         64                  15          HTTP/1.1

sc-win32-status 64 : The specified network name is no longer available.

sc-status 400 : Bad request

Also some requests takes around 130 seconds, but some of less than 1 second. This is a windows application which connects to a web service for process some data. There is not a query takes around 130 seconds on the database.

Best Answer

You're looking at the HTTPERR logs, but they might not be the whole story.

There's a reference for what each code means here: 820729 and in short, the only point of concern above is the POST which was disallowed for taking too long (Timer_EntityBody - i.e. the entity body was not received before the HTTPAPI-configured timeout from your app).

It's unclear whether you're hosting this app in IIS, but I'd suggest that if you're getting those errors, you investigate them at the app level (\inetpub\logs\w3svcxxx) rather than the system level (\windows\system32\logfiles\httperr).

The App logs are likely to contain any app-level errors, problems or burps, and there might also be evidence in the Application event log, in EventVwr.

Related Topic