Date: Mon, 05 Nov 2012 10:18:33 +0100 From: Andre Oppermann <andre@freebsd.org> To: Fabian Keil <freebsd-listen@fabiankeil.de> Cc: freebsd-net@freebsd.org Subject: Re: kern/173309: [tcp] TCP connections often prematurely closed by the server side after r242262 [regression] Message-ID: <50978469.8000001@freebsd.org> In-Reply-To: <20121105002509.670ca1fc@fabiankeil.de> References: <201211032251.qA3Mpnp6017076@freefall.freebsd.org> <5095B953.9060301@freebsd.org> <20121104132957.3965dc99@fabiankeil.de> <5096C6CA.4090306@freebsd.org> <20121104225226.500507a3@fabiankeil.de> <5096E8FD.6040103@freebsd.org> <20121105002509.670ca1fc@fabiankeil.de>
next in thread | previous in thread | raw e-mail | index | archive | help
On 05.11.2012 00:25, Fabian Keil wrote: > Andre Oppermann <andre@freebsd.org> wrote: > >> On 04.11.2012 22:52, Fabian Keil wrote: >>> Andre Oppermann <andre@freebsd.org> wrote: > >>>> The patch I sent was not correct. Please try this new attached patch >>>> instead. >>> >>> This seems to fix the issue for connections between curl and gatling, >> >> That's good. >> >>> I'm still frequently seeing problems with curl and Privoxy, though: >>> >>> fk@r500 ~ $echo $http_proxy >>> http://10.0.0.1:8118/ >>> fk@r500 ~ $i=1; while curl -o /dev/zero 'http://127.0.0.1:81/90k-file'; do echo $i; ((i=$i+1)); done >>> % Total % Received % Xferd Average Speed Time Time Time Current >>> Dload Upload Total Spent Left Speed >>> 100 90000 100 90000 0 0 364k 0 --:--:-- --:--:-- --:--:-- 366k >>> 1 >>> % Total % Received % Xferd Average Speed Time Time Time Current >>> Dload Upload Total Spent Left Speed >>> 100 90000 100 90000 0 0 799k 0 --:--:-- --:--:-- --:--:-- 806k >>> 2 >>> % Total % Received % Xferd Average Speed Time Time Time Current >>> Dload Upload Total Spent Left Speed >>> 99 90000 99 89742 0 0 363k 0 --:--:-- --:--:-- --:--:-- 365k >>> curl: (18) transfer closed with 258 bytes remaining to read >> >> This message from curl points to a problem in the interaction between the >> server and curl. See this description: >> http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=572276 >> >> So unless you can rule out a curl/privoxy interop issue and with gatling it >> is working reliably we can assume this particular TCP problem to be fixed. >> >> Here on my test machine with nginx it works realiably as well again. There >> is an interesting edge case with socket buffer autoscaling on loopback but >> that is neither fatal nor related to this problem. > > Sorry, my description was a bit misleading. I didn't mean that Privoxy is > generating HTTP chunks (in which case the Debian bug might apply), > but that it uses one write() call per ~4999 bytes of data. > > I work on Privoxy upstream, the regression tests rely on curl and > there weren't any (known) compatibility issues before r242262. > > In the above setup, Privoxy is acting as proxy between curl and gatling > and just passes on the received data in a read/write loop. > > If I let curl request a document Privoxy serves itself and thus can > send it with a single write() call, the problem happens a lot less > often. > > Probably your nginx setup is closer to this scenario. Maybe you can > reproduce the problem by running two nginx instances and letting > the first one act as a proxy before the second one. > >>> In this cases Privoxy wrote most of the response body in chunks of >>> 4999 bytes, near the end of the transfer write() returned -1: >> >> The write returns -1 because the client (curl) has closed the socket and >> the last write can be accepted anymore. Curl has prematurely closed the >> connection. > > The tcpdump from my previous message seems to show that the server > side is closing the connection: > > 22:34:01.355049 IP (tos 0x0, ttl 64, id 31075, offset 0, flags [DF], proto TCP (6), length 3716) > 10.0.0.1.8118 > 10.0.0.1.55930: Flags [FP.], seq 86349:90013, ack 203, win 1275, options [nop,nop,TS val 3752298641 ecr 1684019220], length 3664 > 22:34:01.355107 IP (tos 0x0, ttl 64, id 31076, offset 0, flags [DF], proto TCP (6), length 64) > 10.0.0.1.55930 > 10.0.0.1.8118: Flags [.], seq 203, ack 70017, win 1275, options [nop,nop,TS val 1684019220 ecr 3752298641,nop,nop,sack 1 {86349:90013}], length 0 > 22:34:01.588185 IP (tos 0x0, ttl 64, id 31079, offset 0, flags [DF], proto TCP (6), length 16384) > 10.0.0.1.8118 > 10.0.0.1.55930: Flags [.], seq 70017:86349, ack 203, win 1275, options [nop,nop,TS val 3752298875 ecr 1684019220], length 16332 > 22:34:01.588268 IP (tos 0x0, ttl 64, id 31080, offset 0, flags [DF], proto TCP (6), length 52) > 10.0.0.1.55930 > 10.0.0.1.8118: Flags [.], seq 203, ack 90014, win 963, options [nop,nop,TS val 1684019454 ecr 3752298875], length 0 > 22:34:01.588946 IP (tos 0x0, ttl 64, id 31081, offset 0, flags [DF], proto TCP (6), length 52) > 10.0.0.1.55930 > 10.0.0.1.8118: Flags [F.], seq 203, ack 90014, win 1275, options [nop,nop,TS val 1684019454 ecr 3752298875], length 0 > 22:34:01.588999 IP (tos 0x0, ttl 64, id 31082, offset 0, flags [DF], proto TCP (6), length 52) > 10.0.0.1.8118 > 10.0.0.1.55930: Flags [.], seq 90014, ack 204, win 1275, options [nop,nop,TS val 3752298875 ecr 1684019454], length 0 Thank you for the detailed report and testing. I've backed out the change with r242601 as it exhibits still too many problems. I'll fix these problems in the next days but in the mean time HEAD should be in a working state. I'll be grateful if I could send you the fixed change for testing before it goes into HEAD again. -- Andre
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?50978469.8000001>