I am having the weirdest issue: I have a web server which sometimes, only on very specific requests, will send a RST to the client after having sent the FIN datagram. First, a description of the setup:
The server runs on an Ubuntu 12.04.1 LTS, which itself is a VM guest inside a Win7 x64 host, in bridged mode. ufw is disabled on the host
The client runs on a iOS simulator, which runs on OS X Mountain Lion, which is a VM guest (hackintosh) inside a Win7 x64 host, in bridged mode.
Both client and server are on the same LAN, one is connected to the home router via an Ethernet cable, and then other thru WiFi.
I happened to glimpse over the server's http logs and found that the client sometimes issuing multiple subsequent identical requests. Further investigation led me to discover that this happens when the server sends a RST, and that the client is simply re-trying.
I am attaching several tcpdump's:
Good1 is the server-side tcpdump of a good session ("good" meaning no RST was generated).
Good3 is another sever-side tcpdump of a good session.
(The difference between Good1 and Good3 is the order in which ACK's were sent from the server to the client, ACK'ing the client's request. The client's request arives in 2 segements (specifically: one for the http headers, and another for a body containing an empty json object, "{}"). In Good1, the server ACK's both request segments, using 2 ACK segments, after the second request has arrived. In Good3, the server ACK's each request segment with an ACK segment as soon as the request segment arrives. Not that it should make a difference.)
Bad1 is a dump, both client- and server-side, of a bad session.
Bad2 is another bad session, this time server-side only.
Note that in all "bad" sessions, the server ACK's each request segments immediately after having received it. I've looked at a few other bad sessions, and the situation is the same in all of them.
But this is also the behavior in "Good3", so I don't see how that observation helps me, of for that matter why it should matter.
I can't find any difference between good and bad sessions, or at least one that I think should matter.
My question is: why are those RST's being generated?
Or at least: how do I go about debugging this, or providing more info here that'll help?
Edit 2 new facts that I have learned:
Section 4.2.2.13 of the RFC (1122) (and Wikipedia, in the article "TCP", under "Connection Termination") says that a TCP application on one host may close the connection before it has read all of the data in its socket buffer, and in such a case the TCP on the host will sent a RST to the other side, to let it know that not all the data it has sent has been read. I'm not sure I completely understand this, since closing my side of the connection still allows me to read, no? It also means that I can't write any more.
I am not sure this is relevant, though, since I see a RST after FIN.
There are multiple complaints of this happening with wsgiref (Python's dev-mode HTTP server), which is exactly what I'm using.
I'll keep updating as I find out more.
Thanks!
~~~~~~~~~~~~~~~~~~~~
Good1 -- Server Side
~~~~~~~~~~~~~~~~~~~~
13:28:02.308319 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [S], seq 94268074, win 65535, options [mss 1460,nop,wscale 4,nop,nop,TS val 943308864 ecr 0,sackOK,eol], length 0
13:28:02.308336 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [S.], seq 1726304574, ack 94268075, win 14480, options [mss 1460,sackOK,TS val 326480982 ecr 943308864,nop,wscale 3], length 0
13:28:02.309750 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [.], ack 1, win 8235, options [nop,nop,TS val 943308865 ecr 326480982], length 0
13:28:02.310744 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [P.], seq 1:351, ack 1, win 8235, options [nop,nop,TS val 943308865 ecr 326480982], length 350
13:28:02.310766 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [P.], seq 351:353, ack 1, win 8235, options [nop,nop,TS val 943308865 ecr 326480982], length 2
13:28:02.310841 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [.], ack 351, win 1944, options [nop,nop,TS val 326480983 ecr 943308865], length 0
13:28:02.310918 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [.], ack 353, win 1944, options [nop,nop,TS val 326480983 ecr 943308865], length 0
13:28:02.315931 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [P.], seq 1:18, ack 353, win 1944, options [nop,nop,TS val 326480984 ecr 943308865], length 17
13:28:02.316107 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [FP.], seq 18:684, ack 353, win 1944, options [nop,nop,TS val 326480984 ecr 943308865], length 666
13:28:02.317651 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [.], ack 18, win 8234, options [nop,nop,TS val 943308872 ecr 326480984], length 0
13:28:02.318288 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [.], ack 685, win 8192, options [nop,nop,TS val 943308872 ecr 326480984], length 0
13:28:02.318640 IP 192.168.1.51.51479 > 192.168.1.132.5000: Flags [F.], seq 353, ack 685, win 8192, options [nop,nop,TS val 943308872 ecr 326480984], length 0
13:28:02.318651 IP 192.168.1.132.5000 > 192.168.1.51.51479: Flags [.], ack 354, win 1944, options [nop,nop,TS val 326480985 ecr 943308872], length 0
~~~~~~~~~~~~~~~~~~~~
Good3 -- Server Side
~~~~~~~~~~~~~~~~~~~~
13:28:03.311143 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [S], seq 1982901126, win 65535, options [mss 1460,nop,wscale 4,nop,nop,TS val 943309853 ecr 0,sackOK,eol], length 0
13:28:03.311155 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [S.], seq 2245063571, ack 1982901127, win 14480, options [mss 1460,sackOK,TS val 326481233 ecr 943309853,nop,wscale 3], length 0
13:28:03.312671 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [.], ack 1, win 8235, options [nop,nop,TS val 943309854 ecr 326481233], length 0
13:28:03.313330 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [P.], seq 1:351, ack 1, win 8235, options [nop,nop,TS val 943309855 ecr 326481233], length 350
13:28:03.313337 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [.], ack 351, win 1944, options [nop,nop,TS val 326481234 ecr 943309855], length 0
13:28:03.313342 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [P.], seq 351:353, ack 1, win 8235, options [nop,nop,TS val 943309855 ecr 326481233], length 2
13:28:03.313346 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [.], ack 353, win 1944, options [nop,nop,TS val 326481234 ecr 943309855], length 0
13:28:03.327942 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [P.], seq 1:18, ack 353, win 1944, options [nop,nop,TS val 326481237 ecr 943309855], length 17
13:28:03.328253 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [FP.], seq 18:684, ack 353, win 1944, options [nop,nop,TS val 326481237 ecr 943309855], length 666
13:28:03.329076 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [.], ack 18, win 8234, options [nop,nop,TS val 943309868 ecr 326481237], length 0
13:28:03.329688 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [.], ack 685, win 8192, options [nop,nop,TS val 943309868 ecr 326481237], length 0
13:28:03.330361 IP 192.168.1.51.51486 > 192.168.1.132.5000: Flags [F.], seq 353, ack 685, win 8192, options [nop,nop,TS val 943309869 ecr 326481237], length 0
13:28:03.330370 IP 192.168.1.132.5000 > 192.168.1.51.51486: Flags [.], ack 354, win 1944, options [nop,nop,TS val 326481238 ecr 943309869], length 0
~~~~~~~~~~~~~~~~~~~~
Bad1 -- Server Side
~~~~~~~~~~~~~~~~~~~~
13:28:01.311876 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [S], seq 920400580, win 65535, options [mss 1460,nop,wscale 4,nop,nop,TS val 943307883 ecr 0,sackOK,eol], length 0
13:28:01.311896 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [S.], seq 3103085782, ack 920400581, win 14480, options [mss 1460,sackOK,TS val 326480733 ecr 943307883,nop,wscale 3], length 0
13:28:01.313509 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 1, win 8235, options [nop,nop,TS val 943307884 ecr 326480733], length 0
13:28:01.315614 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [P.], seq 1:351, ack 1, win 8235, options [nop,nop,TS val 943307886 ecr 326480733], length 350
13:28:01.315727 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [.], ack 351, win 1944, options [nop,nop,TS val 326480734 ecr 943307886], length 0
13:28:01.316229 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [P.], seq 351:353, ack 1, win 8235, options [nop,nop,TS val 943307886 ecr 326480733], length 2
13:28:01.316242 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [.], ack 353, win 1944, options [nop,nop,TS val 326480734 ecr 943307886], length 0
13:28:01.321019 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [P.], seq 1:18, ack 353, win 1944, options [nop,nop,TS val 326480735 ecr 943307886], length 17
13:28:01.321294 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [FP.], seq 18:684, ack 353, win 1944, options [nop,nop,TS val 326480736 ecr 943307886], length 666
13:28:01.321386 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R.], seq 685, ack 353, win 1944, options [nop,nop,TS val 326480736 ecr 943307886], length 0
13:28:01.322727 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 18, win 8234, options [nop,nop,TS val 943307891 ecr 326480735], length 0
13:28:01.322733 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R], seq 3103085800, win 0, length 0
13:28:01.323221 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 685, win 8192, options [nop,nop,TS val 943307892 ecr 326480736], length 0
13:28:01.323231 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R], seq 3103086467, win 0, length 0
~~~~~~~~~~~~~~~~~~~~
Bad1 -- Client Side
~~~~~~~~~~~~~~~~~~~~
13:28:11.374654 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [S], seq 920400580, win 65535, options [mss 1460,nop,wscale 4,nop,nop,TS val 943307883 ecr 0,sackOK,eol], length 0
13:28:11.375764 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [S.], seq 3103085782, ack 920400581, win 14480, options [mss 1460,sackOK,TS val 326480733 ecr 943307883,nop,wscale 3], length 0
13:28:11.376352 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 1, win 8235, options [nop,nop,TS val 943307884 ecr 326480733], length 0
13:28:11.378252 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [P.], seq 1:351, ack 1, win 8235, options [nop,nop,TS val 943307886 ecr 326480733], length 350
13:28:11.379027 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [P.], seq 351:353, ack 1, win 8235, options [nop,nop,TS val 943307886 ecr 326480733], length 2
13:28:11.379732 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [.], ack 351, win 1944, options [nop,nop,TS val 326480734 ecr 943307886], length 0
13:28:11.380592 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [.], ack 353, win 1944, options [nop,nop,TS val 326480734 ecr 943307886], length 0
13:28:11.384968 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [P.], seq 1:18, ack 353, win 1944, options [nop,nop,TS val 326480735 ecr 943307886], length 17
13:28:11.385044 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 18, win 8234, options [nop,nop,TS val 943307891 ecr 326480735], length 0
13:28:11.385586 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [FP.], seq 18:684, ack 353, win 1944, options [nop,nop,TS val 326480736 ecr 943307886], length 666
13:28:11.385743 IP 192.168.1.51.51472 > 192.168.1.132.5000: Flags [.], ack 685, win 8192, options [nop,nop,TS val 943307892 ecr 326480736], length 0
13:28:11.385966 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R.], seq 685, ack 353, win 1944, options [nop,nop,TS val 326480736 ecr 943307886], length 0
13:28:11.387343 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R], seq 3103085800, win 0, length 0
13:28:11.387344 IP 192.168.1.132.5000 > 192.168.1.51.51472: Flags [R], seq 3103086467, win 0, length 0
~~~~~~~~~~~~~~~~~~~~
Bad2 -- Server Side
~~~~~~~~~~~~~~~~~~~~
13:28:01.319185 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [S], seq 1631526992, win 65535, options [mss 1460,nop,wscale 4,nop,nop,TS val 943307889 ecr 0,sackOK,eol], length 0
13:28:01.319197 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [S.], seq 2524685719, ack 1631526993, win 14480, options [mss 1460,sackOK,TS val 326480735 ecr 943307889,nop,wscale 3], length 0
13:28:01.320692 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [.], ack 1, win 8235, options [nop,nop,TS val 943307890 ecr 326480735], length 0
13:28:01.322219 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [P.], seq 1:351, ack 1, win 8235, options [nop,nop,TS val 943307890 ecr 326480735], length 350
13:28:01.322336 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [.], ack 351, win 1944, options [nop,nop,TS val 326480736 ecr 943307890], length 0
13:28:01.322689 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [P.], seq 351:353, ack 1, win 8235, options [nop,nop,TS val 943307890 ecr 326480735], length 2
13:28:01.322700 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [.], ack 353, win 1944, options [nop,nop,TS val 326480736 ecr 943307890], length 0
13:28:01.326307 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [P.], seq 1:18, ack 353, win 1944, options [nop,nop,TS val 326480737 ecr 943307890], length 17
13:28:01.326614 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [FP.], seq 18:684, ack 353, win 1944, options [nop,nop,TS val 326480737 ecr 943307890], length 666
13:28:01.326710 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [R.], seq 685, ack 353, win 1944, options [nop,nop,TS val 326480737 ecr 943307890], length 0
13:28:01.328499 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [.], ack 18, win 8234, options [nop,nop,TS val 943307896 ecr 326480737], length 0
13:28:01.328509 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [R], seq 2524685737, win 0, length 0
13:28:01.328514 IP 192.168.1.51.51473 > 192.168.1.132.5000: Flags [.], ack 685, win 8192, options [nop,nop,TS val 943307896 ecr 326480737], length 0
13:28:01.328517 IP 192.168.1.132.5000 > 192.168.1.51.51473: Flags [R], seq 2524686404, win 0, length 0
