From owner-freebsd-net@freebsd.org Thu Jan 7 17:51:57 2016 Return-Path: Delivered-To: freebsd-net@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 9F478A6627D for ; Thu, 7 Jan 2016 17:51:57 +0000 (UTC) (envelope-from Mark.Martinec+freebsd@ijs.si) Received: from mail.ijs.si (mail.ijs.si [IPv6:2001:1470:ff80::25]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 2DFB41B89 for ; Thu, 7 Jan 2016 17:51:57 +0000 (UTC) (envelope-from Mark.Martinec+freebsd@ijs.si) Received: from amavis-ori.ijs.si (localhost [IPv6:::1]) by mail.ijs.si (Postfix) with ESMTP id 3pbw9j22mQz1TC for ; Thu, 7 Jan 2016 18:51:53 +0100 (CET) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=ijs.si; h= user-agent:message-id:references:in-reply-to:organization :subject:subject:from:from:date:date:content-transfer-encoding :content-type:content-type:mime-version:received:received :received:received; s=jakla4; t=1452189109; x=1454781110; bh=8F+ 3CYHvpbGETS2Y5qXCJZ9EaWSzHfvB8/TNjcRPlsM=; b=oOidWRGAqjswEMaUVKj R4BP/MscrTR9yMDgrb5KTZyIf1l2p7I/TX9GxH3r+p8KnK/J8lmtm5FHu6vR1lMe OgAE/moInVi76JEdOp0hfv+aZ/xAQEmrMuei60IP6bAKIY5MnyTeS53qqOqOFBKx XhoyMto91rvNwEoCEsu9B9io= X-Virus-Scanned: amavisd-new at ijs.si Received: from mail.ijs.si ([IPv6:::1]) by amavis-ori.ijs.si (mail.ijs.si [IPv6:::1]) (amavisd-new, port 10026) with LMTP id 7SnWdy4Zja-t for ; Thu, 7 Jan 2016 18:51:49 +0100 (CET) Received: from mildred.ijs.si (mailbox.ijs.si [IPv6:2001:1470:ff80::143:1]) by mail.ijs.si (Postfix) with ESMTP id 3pbw9d5rj0z1T8 for ; Thu, 7 Jan 2016 18:51:49 +0100 (CET) Received: from nabiralnik.ijs.si (nabiralnik.ijs.si [IPv6:2001:1470:ff80::80:16]) by mildred.ijs.si (Postfix) with ESMTP id 3pbw9d3LSxzgg for ; Thu, 7 Jan 2016 18:51:49 +0100 (CET) Received: from neli.ijs.si (2001:1470:ff80:88:21c:c0ff:feb1:8c91) by nabiralnik.ijs.si with HTTP (HTTP/1.1 POST); Thu, 07 Jan 2016 18:51:49 +0100 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit Date: Thu, 07 Jan 2016 18:51:49 +0100 From: Mark Martinec To: freebsd-net@freebsd.org Subject: Re: 250x slowdown on localhost sockets with certain sized write(2) call from perl Organization: Jozef Stefan Institute In-Reply-To: <2392D9E1-CA83-42F2-A3C9-DFF63772539F@mailermailer.com> References: <2392D9E1-CA83-42F2-A3C9-DFF63772539F@mailermailer.com> Message-ID: <7d1d6d177b4996758bf23b440c3b63da@mailbox.ijs.si> X-Sender: Mark.Martinec+freebsd@ijs.si User-Agent: Roundcube Webmail/1.1.4 X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 07 Jan 2016 17:51:57 -0000 This is how TCP works by default (delayed ACK, Nagle). See: http://marc.info/?t=132173691400053&r=1&w=2 Mark On 2016-01-07 18:03, Vick Khera wrote: > I noticed a very curious slowdown in submitting email via a perl > program to a mail server running on the same host. I narrowed it down > to messages which were exactly 16332 bytes or shorted. Once they hit > 16333 bytes, they submit extremely fast. This slowdown only affects > connections on the local host. Connections to a remote mail server are > unaffected. > > I’m not 100% sure if this is a bug in FreeBSD or in Perl’s Net::SMTP > module, but the smallest test case I could come up with is below. My > hunch is that it is FreeBSD’s bug because I cannot reproduce this > problem on several linux versions. > > > How to reproduce it: > > In window A, run "smtp-sink -c -4 :8025 10" with the smtp-sink program > from Postfix. Alternatively, run the "perl-sink" program below, which > requires the p5-Net-SMTP-Server package. You really don’t want to > point the test program at a real mail server, though it does the same > slowdown with postfix when sending a hand-crafted message of the right > size. > > In window B, run "perl standalone-smtp-speed.pl". On my FreeBSD 9.3 > and 10.2 systems, this output looks consistently like this: > > length=16327 elapsed = 0.106297 **SLOW > length=16328 elapsed = 0.108077 **SLOW > length=16329 elapsed = 0.101655 **SLOW > length=16330 elapsed = 0.106082 **SLOW > length=16331 elapsed = 0.10716 **SLOW > length=16332 elapsed = 0.106499 **SLOW > length=16333 elapsed = 0.00041 > length=16334 elapsed = 0.00041 > length=16335 elapsed = 0.000415 > length=16336 elapsed = 0.000367 > > That is, up until the time the length of the message hits 16333 bytes, > it is about 250 times slower to send the message to the mail server. > It does not matter how many before or after messages are sent or what > their lengths are, it is always that length threshold that causes a > material shift in the time it takes. > > Perl’s SMTP send ultimately ends up calling syswrite() from perl, > which is write(2) from C. This is where the slowness comes, it seems. > The syswrite() always completes with one call — no retries are > necessary for short writes. > > If you update the standalone-smtp-speed.pl script to point to the sink > program on a different host, all the lengths run fast. > > I tried to make a test case that just uses syswrite() directly without > the SMTP module, but I couldn’t do it. Maybe it requires some data to > be received too. I don’t know. > > Any ideas as to why? The only clue I found was this kernel PR > referencing the number 16332 as the length of partial writes to a > socket. https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=173309 > > > > _______________________________________________ > freebsd-net@freebsd.org mailing list > https://lists.freebsd.org/mailman/listinfo/freebsd-net > To unsubscribe, send any mail to "freebsd-net-unsubscribe@freebsd.org"