in reply to SOAP::Lite client request over HTTPS hangs until connection is reset by server

The RESET means that the client and the server disagree on the state of the TCP connection that they set up. It usually means "you sent me a packet that claimed to be part of some connection but as far as I, the server, am concerned, that connection doesn't exist". The next step for me would be to look at the packets that lead up to the RESET to better characterize the disagreement. Perhaps it is actually the proxy that is messing things up.

A 60-second time-out is often an indication that a packet has been dropped. But that only makes sense if a packet was dropped in a way that would cause the client to try to send a packet. Or perhaps you have TCP keep-alives enabled?

To some extend, it should not be possible or at least not easy for the client software to cause a violation in the TCP protocol that would lead to a RESET. The closest scenario I was able to come up with for that would be the service sending the response and then closing the connection followed by the client, upon receiving the response (and perhaps even receiving the EOF in the server-to-client direction), trying to send something to the service. But that wouldn't explain the 60-second time-out before the RESET was received.

But you add a proxy into the mix and it might be:

  1. Service sends response and closes the socket
  2. Proxy receives response and forwards it to client
  3. Client receives response
  4. Client sends something more
  5. Proxy receives extra data from client and forwards to service
  6. Server OS sees data for a closed connection and sends RESET to proxy
  7. Proxy closes both sockets (one from client, one to service)
  8. Client hasn't heard a response after 60s and ignores that there is an EOF from the proxy (that it probably already read)
  9. Client re-sends
  10. Proxy OS sends a RESET to the client.

That's obviously just a guess. It was the only scenario I could come up with that didn't involve some device in the mix violating the TCP protocol. (A simple dropped packet is not a protocol violation, but I couldn't come up with a scenario with a dropped packet that would cause the observed behavior and a dropped packet should not be this predictable anyway.)

- tye        

  • Comment on Re: SOAP::Lite client request over HTTPS hangs until connection is reset by server (dig)

Replies are listed 'Best First'.
Re^2: SOAP::Lite client request over HTTPS hangs until connection is reset by server (dig)
by kiteboy (Initiate) on Jan 30, 2015 at 19:51 UTC

    Here is the tcpdump output in case this helps...

    12:33:40.753889 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [S], seq 1988871748, win 14600, options [mss 1460,sackOK,TS val 3709
+013834 ecr 0,nop,wscale 7], length 0
12:33:40.834549 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [S.], seq 1059759601, ack 1988871749, win 8192, options [mss 1460,no
+p,wscale 8,sackOK,TS val 8027727 ecr 3709013834], length 0
12:33:40.834588 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 1, win 115, options [nop,nop,TS val 3709013915 ecr 8027727]
+, length 0
12:33:40.835065 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [P.], seq 1:114, ack 1, win 115, options [nop,nop,TS val 3709013915 
+ecr 8027727], length 113
12:33:40.915976 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 1:1449, ack 114, win 260, options [nop,nop,TS val 8027735 e
+cr 3709013915], length 1448
12:33:40.916003 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 1449:2897, ack 114, win 260, options [nop,nop,TS val 802773
+5 ecr 3709013915], length 1448
12:33:40.916038 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 1449, win 137, options [nop,nop,TS val 3709013996 ecr 80277
+35], length 0
12:33:40.916077 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 2897, win 160, options [nop,nop,TS val 3709013996 ecr 80277
+35], length 0
12:33:40.916079 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 2897:4345, ack 114, win 260, options [nop,nop,TS val 802773
+5 ecr 3709013915], length 1448
12:33:40.916094 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 4345:4441, ack 114, win 260, options [nop,nop,TS val 80277
+35 ecr 3709013915], length 96
12:33:40.916111 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 4345, win 182, options [nop,nop,TS val 3709013996 ecr 80277
+35], length 0
12:33:40.916118 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 4441, win 182, options [nop,nop,TS val 3709013996 ecr 80277
+35], length 0
12:33:40.918573 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [P.], seq 114:440, ack 4441, win 182, options [nop,nop,TS val 370901
+3998 ecr 8027735], length 326
12:33:41.001844 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 4441:4500, ack 440, win 258, options [nop,nop,TS val 80277
+44 ecr 3709013998], length 59
12:33:41.029525 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], seq 440:1888, ack 4500, win 182, options [nop,nop,TS val 370901
+4109 ecr 8027744], length 1448
12:33:41.029547 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [P.], seq 1888:2109, ack 4500, win 182, options [nop,nop,TS val 3709
+014110 ecr 8027744], length 221
12:33:41.109808 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], ack 2109, win 260, options [nop,nop,TS val 8027755 ecr 37090141
+09], length 0
12:33:41.110310 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 4500:4537, ack 2109, win 260, options [nop,nop,TS val 8027
+755 ecr 3709014109], length 37
12:33:41.110738 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [P.], seq 2109:2258, ack 4537, win 182, options [nop,nop,TS val 3709
+014191 ecr 8027755], length 149
12:33:41.191800 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 4537:5985, ack 2258, win 259, options [nop,nop,TS val 80277
+63 ecr 3709014191], length 1448
12:33:41.191826 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 5985:7433, ack 2258, win 259, options [nop,nop,TS val 80277
+63 ecr 3709014191], length 1448
12:33:41.191906 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 7433:8881, ack 2258, win 259, options [nop,nop,TS val 80277
+63 ecr 3709014191], length 1448
12:33:41.191920 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 8881:10329, ack 2258, win 259, options [nop,nop,TS val 8027
+763 ecr 3709014191], length 1448
12:33:41.191925 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 10329:10638, ack 2258, win 259, options [nop,nop,TS val 80
+27763 ecr 3709014191], length 309
12:33:41.192005 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 7433, win 228, options [nop,nop,TS val 3709014272 ecr 80277
+63], length 0
12:33:41.192041 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 10329, win 273, options [nop,nop,TS val 3709014272 ecr 8027
+763], length 0
12:33:41.201453 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], seq 2258:3706, ack 10638, win 296, options [nop,nop,TS val 3709
+014281 ecr 8027763], length 1448
12:33:41.201494 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [P.], seq 3706:4795, ack 10638, win 296, options [nop,nop,TS val 370
+9014282 ecr 8027763], length 1089
12:33:41.281673 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], ack 4795, win 260, options [nop,nop,TS val 8027772 ecr 37090142
+81], length 0
12:33:41.286499 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 10638:10728, ack 4795, win 260, options [nop,nop,TS val 80
+27772 ecr 3709014281], length 90
12:33:41.326420 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 10728, win 296, options [nop,nop,TS val 3709014407 ecr 8027
+772], length 0
12:33:41.367848 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 10728:12176, ack 4795, win 260, options [nop,nop,TS val 802
+7780 ecr 3709014281], length 1448
12:33:41.367861 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 12176:13624, ack 4795, win 260, options [nop,nop,TS val 802
+7780 ecr 3709014281], length 1448
12:33:41.367917 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 13624:15072, ack 4795, win 260, options [nop,nop,TS val 802
+7780 ecr 3709014281], length 1448
12:33:41.367924 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [.], seq 15072:16520, ack 4795, win 260, options [nop,nop,TS val 802
+7780 ecr 3709014281], length 1448
12:33:41.367927 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [P.], seq 16520:17090, ack 4795, win 260, options [nop,nop,TS val 80
+27780 ecr 3709014281], length 570
12:33:41.368007 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 12176, win 318, options [nop,nop,TS val 3709014448 ecr 8027
+780], length 0
12:33:41.368042 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 13624, win 341, options [nop,nop,TS val 3709014448 ecr 8027
+780], length 0
12:33:41.368047 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 15072, win 363, options [nop,nop,TS val 3709014448 ecr 8027
+780], length 0
12:33:41.368052 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 16520, win 386, options [nop,nop,TS val 3709014448 ecr 8027
+780], length 0
12:33:41.368056 IP 10.90.52.10.53276 > api.login.live.com.https: Flags
+ [.], ack 17090, win 409, options [nop,nop,TS val 3709014448 ecr 8027
+780], length 0
12:34:42.285114 IP api.login.live.com.https > 10.90.52.10.53276: Flags
+ [R.], seq 17090, ack 4795, win 0, length 0

    [download]
[reply]
[d/l]

      One thing is easy to spot. The RESET is not a response to a client-side time-out, it is the result of a server-side (or perhaps proxy-side) time-out.

      Looks like your client is not noticing that it got a full response. After 60s of idleness, the server resets the connection. I would have expected that to be done via a FIN packet not a RST packet. Perhaps this is to blame:

      If such a host actively closes a connection but still has not read all the incoming data the stack already received from the link, this host sends a RST instead of a FIN

      But that would require a bug in the service, I think, which seems less likely in most environments.

      - tye        

[reply]

In Section Seekers of Perl Wisdom