High time difference between ClientDoneRequest and ServerConnected.

[pradeep]

Hi ,

Can any one suggest the possible reason of high time difference between ClientDoneRequest and ServerConnected. Is it something related to web server or application or network issue?

ClientConnected: 13:12:11.926

ClientBeginRequest: 13:12:18.417

GotRequestHeaders: 13:12:18.417

ClientDoneRequest: 13:12:18.417

Determine Gateway: 0ms

DNS Lookup: 78ms

TCP/IP Connect: 3ms

HTTPS Handshake: 0ms

ServerConnected: 13:20:38.417

FiddlerBeginRequest: 13:20:38.417

ServerGotRequest: 13:20:38.418

ServerBeginResponse: 13:20:38.550

GotResponseHeaders: 13:20:38.550

ServerDoneResponse: 13:20:38.550

ClientBeginResponse: 13:20:38.550

ClientDoneResponse: 13:20:38.550

Thanks,

 Pradeep

[EricLaw]

Right-click the session, choose Properties, and copy the data from the screen into a reply to this message.

[pradeep]

Hi Eric, 

Appreciate for your response. Below is that data. This is not the same fiddler session but in this session we also got the issue:

SESSION STATE: Done.

Response Entity Size: 0 bytes.

== FLAGS ==================

BitFlags: [ClientPipeReused, LoadedFromSAZ] 0x208

UI-BOLD: user-marked

UI-COLOR: Red

UI-COMMENTS: [#6]

UI-OLDCOLOR: Gray

X-CLIENTIP: 127.0.0.1

X-CLIENTPORT: 61214

X-EGRESSPORT: 61356

X-HOSTIP: 23.220.249.183

X-PROCESSINFO: firefox:1124

X-RESPONSEBODYTRANSFERLENGTH: 0

X-RETRYONFAILEDRECEIVE: *

X-SERVERSOCKET: REUSE ServerPipe#4*NEW*

== TIMING INFO ============

This traffic was captured on Thursday, October 02, 2014.

ClientConnected: 13:04:13.722

ClientBeginRequest: 13:05:55.220

GotRequestHeaders: 13:05:55.220

ClientDoneRequest: 13:05:55.220

Determine Gateway: 0ms

DNS Lookup: 78ms

TCP/IP Connect: 1ms

HTTPS Handshake: 0ms

ServerConnected: 13:09:00.238

FiddlerBeginRequest: 13:09:00.238

ServerGotRequest: 13:09:00.239

ServerBeginResponse: 13:09:00.374

GotResponseHeaders: 13:09:00.374

ServerDoneResponse: 13:09:00.374

ClientBeginResponse: 13:09:00.374

ClientDoneResponse: 13:09:00.374

Overall Elapsed: 00:03:05.1535902

The response was buffered before delivery to the client.

== WININET CACHE INFO ============

Url: http://appinfo.com/root/rootbasepage/scripts/basepagescripts.js?bn=5.151.37.9

Cache File: C:\Users\pradeep.mishra\AppData\Local\Microsoft\Windows\Temporary Internet Files\Content.IE5\1MC0GPWP\basepagescripts[1].js

Size: 21,520 bytes

File Extension:

Hit Rate: 18

Use Count: 0

Don't Scavenge for: 0 seconds

Last Modified: 5/15/2014 1:54:34 AM

Last Accessed: 10/2/2014 12:23:51 PM

Last Synced:   10/2/2014 12:23:51 PM

Entry Expires: 10/2/2014 11:23:51 AM

* Note: Data above shows WinINET's current cache state, not the state at the time of the request.

* Note: Data above shows WinINET's Medium Integrity (non-Protected Mode) cache only.

I Could understand from  X-RETRYONFAILEDRECEIVE: * ,X-SERVERSOCKET: REUSE ServerPipe#4*NEW*   like fiddler could not reuse connection and on failing it made new one. But what could be the reason of failing? Is It client network issue or how could we trace the root cause of it?

Thanks,

Pradeep

[EricLaw]

Yes, this:

  X-RETRYONFAILEDRECEIVE: *

  X-SERVERSOCKET: REUSE ServerPipe#4*NEW*

Means that the client reused an existing connection to the server, but the server failed to return a proper response and Fiddler was forced to try again on a new connection. The fact that the delay was so long (minutes) strongly suggests that the server sent an incomplete response over several minutes, then abruptly killed the connection (e.g. using a TCP/IP RST) and Fiddler then retried on a new connection.

This could indicate a problem in your network infrastructure, or a bug in your application (whereby it fails to properly indicate the response length).

What was the HTTP response status code for this response? Can you send (Help > Send Feedback) a SAZ file containing an example?

This:

   X-RESPONSEBODYTRANSFERLENGTH: 0

Indicates that the response body was zero-bytes long, which seems pretty odd.

[pradeep]

Hi Eric,

Response status code was 304. Since it was static file and cached hence server have sent 304 (not modified status) and so response length was 0. Is there any tool where I could profile the network.  I got one properties info for a css where 200 response status was appeared. here you will get the response length also. 

SESSION STATE: Done.

Response Entity Size: 8440 bytes.

== FLAGS ==================

BitFlags: [ClientPipeReused, ServerPipeReused, ResponseStreamed, LoadedFromSAZ] 0x258

UI-COMMENTS: [#588]

X-CLIENTIP: 127.0.0.1

X-CLIENTPORT: 51446

X-EGRESSPORT: 51917

X-HOSTIP: 23.72.71.9

X-PROCESSINFO: chrome:12024

X-RESPONSEBODYTRANSFERLENGTH: 1212

X-SERVERSOCKET: REUSE ServerPipe#494

== TIMING INFO ============

This traffic was captured on Thursday, September 25, 2014.

ClientConnected: 15:00:03.837

ClientBeginRequest: 15:08:59.382

GotRequestHeaders: 15:08:59.382

ClientDoneRequest: 15:08:59.382

Determine Gateway: 0ms

DNS Lookup: 0ms

TCP/IP Connect: 0ms

HTTPS Handshake: 0ms

ServerConnected: 15:08:59.210

FiddlerBeginRequest: 15:08:59.382

ServerGotRequest: 15:08:59.382

ServerBeginResponse: 15:08:59.467

GotResponseHeaders: 15:08:59.467

ServerDoneResponse: 15:08:59.467

ClientBeginResponse: 15:08:59.467

ClientDoneResponse: 15:08:59.467

Overall Elapsed: 00:00:00.0850085

The response was streamed to the client as it was received.

== WININET CACHE INFO ============

Url: http://appinfo.com/App/app_themes/btn.css

Cache File: C:\Users\pradeep.mishra\AppData\Local\Microsoft\Windows\Temporary Internet Files\Content.IE5\65C2T1Y6\btn[1].css

Size: 8,440 bytes

File Extension:

Hit Rate: 11

Use Count: 0

Don't Scavenge for: 0 seconds

Last Modified: 7/10/2014 2:24:30 PM

Last Accessed: 10/2/2014 11:25:50 AM

Last Synced:   10/2/2014 11:25:50 AM

Entry Expires: 10/2/2014 10:25:50 AM

* Note: Data above shows WinINET's current cache state, not the state at the time of the request.

* Note: Data above shows WinINET's Medium Integrity (non-Protected Mode) cache only.

Thanks,

Pradeep

[EricLaw]

If you can reliably repro a problem like this, a Wireshark .PCAP or NetMon .CAP file will allow us to see what's happening at the lower-level network.

Seeing this problem for a 304 seems very strange, particularly with such a long delay, as Fiddler has a network timeout of around a minute (per read), and a bodyless response like a 304 will typically have just one read (the headers).