Return-Path: Delivered-To: new-httpd-archive@hyperreal.org Received: (qmail 8326 invoked by uid 6000); 11 Jan 1998 17:14:16 -0000 Received: (qmail 8320 invoked from network); 11 Jan 1998 17:14:14 -0000 Received: from valis.worldgate.com (marcs@198.161.84.2) by taz.hyperreal.org with SMTP; 11 Jan 1998 17:14:14 -0000 Received: from localhost (marcs@localhost) by valis.worldgate.com (8.8.7/8.8.7) with SMTP id KAA14557 for ; Sun, 11 Jan 1998 10:14:13 -0700 (MST) Date: Sun, 11 Jan 1998 10:14:13 -0700 (MST) From: Marc Slemko To: new-httpd@apache.org Subject: Re: Win32 network glitch In-Reply-To: Message-ID: MIME-Version: 1.0 Content-Type: MULTIPART/MIXED; BOUNDARY="-1463811070-754712952-884536996=:30719" Content-ID: Sender: new-httpd-owner@apache.org Precedence: bulk Reply-To: new-httpd@apache.org This message is in MIME format. The first part should be readable text, while the remaining parts are likely unreadable without MIME-aware tools. Send mail to mime@docserver.cac.washington.edu for more info. ---1463811070-754712952-884536996=:30719 Content-Type: TEXT/PLAIN; CHARSET=US-ASCII Content-ID: On Sun, 11 Jan 1998, Paul Sutton wrote: > Help! Every so often Apache in Win32 slows down for a few seconds when > subject to serial repeated hits. I've taken a tcpdump but I'm not familiar > enough with TCP to know whether this is a bug in NT's tcp stuff. Could > someone have a look please? > > In more detail, I've written a perl script which repeatly connects to a > server, requests a document, reads the response, and disconnections. I've > been using this to test for resource leaks etc on Apache NT. But every so > often (say around 50-300 requests, although it doesn't seem to be > determinable), the "connect" call will take several seconds to complete. > Sometimes it goes back to normal after the connect completes, at other > times serveral more connects (up to about ten) will also be "slow" before > it goes back to normal speed. The client here is running on Linux 2.0.29. > > Now I thought I'd use tcpdump to see what part of the connection is slow, > and the result is in the attachment. The first request is ok, then at > 16:17:27.290000 it starts a new connect. The next few lines logged are > (ecstasy.localnet is the Linux client, beavis.localnet is the NT Apache > server, the request is 12 bytes long, the response 46750): > > 16:17:27.290000 ecstasy.localnet.1819 > beavis.localnet.8001: S 769576620:769576 > 620(0) win 512 Good. > 16:17:27.290000 beavis.localnet.8001 > ecstasy.localnet.1819: . ack 13 win 8749 > (DF) This looks like there is a connection in TIME_WAIT on the server so it sends an ACK on the old connection since the SYN isn't in the window. In this case, most BSD stacks would follow section 4.2.2.13 of RFC-1122: When a connection is closed actively, it MUST linger in TIME-WAIT state for a time 2xMSL (Maximum Segment Lifetime). However, it MAY accept a new SYN from the remote TCP to reopen the connection directly from TIME-WAIT state, if it: (1) assigns its initial sequence number for the new connection to be larger than the largest sequence number it used on the previous connection incarnation, and (2) returns to TIME-WAIT state if the SYN turns out to be an old duplicate. so you don't have this problem. Although I don't think Linux implements this either... > 16:17:27.290000 ecstasy.localnet.1819 > beavis.localnet.8001: R 745127567:745127 > 567(0) win 0 The Linux box logically says "what the heck is this?" > 16:17:30.290000 ecstasy.localnet.1819 > beavis.localnet.8001: S 769576620:769576 > 620(0) win 31744 ...and resends the syn once it times out. > 16:17:30.290000 beavis.localnet.8001 > ecstasy.localnet.1819: S 79075915:7907591 > 5(0) ack 769576621 win 8760 (DF) This time it is ok because the previous connection attempt has (bogusly) assasinated the TIME_WAIT connection. Well, I guess it could have just timed out but ISTR that NT does early assassination. > 16:17:30.290000 ecstasy.localnet.1819 > beavis.localnet.8001: . ack 1 win 31744 > > It looks to me like the Linux client (ecstasy) is initiating the > connection, but the NT server is not acknowledging it correctly -- the ack > 13 is the sequence number of the _previous_ connection which has just been > closed down... here are the tcpdump lines just prior to the above lines: No, it isn't. Do a tcpdump -S and you will probably find them wildly different. > > 16:17:27.270000 beavis.localnet.8001 > ecstasy.localnet.1814: F 46751:46751(0) a > ck 12 win 8749 (DF) > 16:17:27.270000 ecstasy.localnet.1814 > beavis.localnet.8001: . ack 46752 win 31 > 744 > 16:17:27.270000 ecstasy.localnet.1814 > beavis.localnet.8001: F 12:12(0) ack 467 > 52 win 31744 > 16:17:27.270000 beavis.localnet.8001 > ecstasy.localnet.1814: . ack 13 win 8749 > (DF) > > Note that the last line is identical to the one that the NT server sends > again at 16:17:27.290000 -- except that the second time it goes to port > 1819 on the Linux client rather than 1814. This is obviously out of > sequence on port 1819 since no data has been sent, so Linux sends a reset > for this connection, and tries again three seconds later. The time the > connection works -- NT acknowledges with a SYN package. > > Is this a correct interpretation? If so, does it mean that this is an NT > winsock bug because it is sending an ack to the wrong port after the > closedown of a previous connection? But if that was the case surely every > network service would have hit this problem and it would be widely known? No, the two connections are unrelated. You are being tricked by tcpdump's relative sequence numbers. Use -S to see the real story. Take a longer term tcpdump and see when the _previous_ connection from the client to the server on that port was. I would bet it is <2*MSL so you still have it hanging around in TIME_WAIT. Nothing that you would normally see unless one client is making a lot of requests to one server. ---1463811070-754712952-884536996=:30719--