From owner-freebsd-net@FreeBSD.ORG Sun Nov 4 22:15:29 2012 Return-Path: Delivered-To: freebsd-net@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id AB4172E1 for ; Sun, 4 Nov 2012 22:15:29 +0000 (UTC) (envelope-from andre@freebsd.org) Received: from c00l3r.networx.ch (c00l3r.networx.ch [62.48.2.2]) by mx1.freebsd.org (Postfix) with ESMTP id 00EF78FC08 for ; Sun, 4 Nov 2012 22:15:28 +0000 (UTC) Received: (qmail 43158 invoked from network); 4 Nov 2012 23:51:13 -0000 Received: from c00l3r.networx.ch (HELO [127.0.0.1]) ([62.48.2.2]) (envelope-sender ) by c00l3r.networx.ch (qmail-ldap-1.03) with SMTP for ; 4 Nov 2012 23:51:13 -0000 Message-ID: <5096E8FD.6040103@freebsd.org> Date: Sun, 04 Nov 2012 23:15:25 +0100 From: Andre Oppermann User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0) Gecko/20121010 Thunderbird/16.0.1 MIME-Version: 1.0 To: Fabian Keil Subject: Re: kern/173309: [tcp] TCP connections often prematurely closed by the server side after r242262 [regression] References: <201211032251.qA3Mpnp6017076@freefall.freebsd.org> <5095B953.9060301@freebsd.org> <20121104132957.3965dc99@fabiankeil.de> <5096C6CA.4090306@freebsd.org> <20121104225226.500507a3@fabiankeil.de> In-Reply-To: <20121104225226.500507a3@fabiankeil.de> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-net@FreeBSD.org, null@pozo.com X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 04 Nov 2012 22:15:30 -0000 On 04.11.2012 22:52, Fabian Keil wrote: > Andre Oppermann wrote: > >> On 04.11.2012 13:29, Fabian Keil wrote: >>> Andre Oppermann wrote: >>> >>>> thank you for the bug report. Please try the attached patch >>>> which should fix the issue you observed. >>> >>> Thanks for the patch, Andre. >>> >>> It seems to make the transfers 100% reliably again, >>> but they are frequently very slow: > >> 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. > 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. -snip- > Most of the time the failures aren't logged by the kernel, > but occasionally they result in messages like these: > > Nov 4 22:44:15 r500 kernel: [1431] TCP: [10.0.0.1]:81 to [10.0.0.1]:10946 tcpflags 0x18; tcp_do_segment: FIN_WAIT_2: Received 284 bytes of data after socket was closed, sending RST and removing tcpcb > Nov 4 22:44:29 r500 kernel: [1445] TCP: [10.0.0.1]:81 to [10.0.0.1]:45803 tcpflags 0x18; tcp_do_segment: FIN_WAIT_2: Received 284 bytes of data after socket was closed, sending RST and removing tcpcb > Nov 4 22:45:52 r500 kernel: [1527] TCP: [10.0.0.1]:81 to [10.0.0.1]:30760 tcpflags 0x18; tcp_do_segment: FIN_WAIT_2: Received 284 bytes of data after socket was closed, sending RST and removing tcpcb > Nov 4 22:45:55 r500 kernel: [1531] TCP: [10.0.0.1]:81 to [10.0.0.1]:62527 tcpflags 0x18; tcp_do_segment: FIN_WAIT_2: Received 284 bytes of data after socket was closed, sending RST and removing tcpcb > Nov 4 22:45:58 r500 kernel: [1534] TCP: [10.0.0.1]:81 to [10.0.0.1]:45876 tcpflags 0x18; tcp_do_segment: FIN_WAIT_2: Received 284 bytes of data after socket was closed, sending RST and removing tcpcb When the socket was abruptly closed by the client and the server still had data in flight you're going to see this message. This is normal and expected. -- Andre