Date: Thu, 7 Jan 2016 12:03:29 -0500 From: Vick Khera <vivek@mailermailer.com> To: freebsd-net@freebsd.org Subject: 250x slowdown on localhost sockets with certain sized write(2) call from perl Message-ID: <2392D9E1-CA83-42F2-A3C9-DFF63772539F@mailermailer.com>
next in thread | raw e-mail | index | archive | help
--Apple-Mail=_28465A14-1206-49C8-A6B8-CE07E76BCD1C Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 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=E2=80=99m not 100% sure if this is a bug in FreeBSD or in Perl=E2=80=99s= Net::SMTP module, but the smallest test case I could come up with is = below. My hunch is that it is FreeBSD=E2=80=99s 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=E2=80=99t 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=3D16327 elapsed =3D 0.106297 **SLOW length=3D16328 elapsed =3D 0.108077 **SLOW length=3D16329 elapsed =3D 0.101655 **SLOW length=3D16330 elapsed =3D 0.106082 **SLOW length=3D16331 elapsed =3D 0.10716 **SLOW length=3D16332 elapsed =3D 0.106499 **SLOW length=3D16333 elapsed =3D 0.00041 length=3D16334 elapsed =3D 0.00041 length=3D16335 elapsed =3D 0.000415 length=3D16336 elapsed =3D 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=E2=80=99s 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 =E2=80=94 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=E2=80=99t do it. Maybe it requires some = data to be received too. I don=E2=80=99t 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=3D173309 --Apple-Mail=_28465A14-1206-49C8-A6B8-CE07E76BCD1C Content-Disposition: attachment; filename=perl-sink Content-Type: application/octet-stream; name="perl-sink" Content-Transfer-Encoding: 7bit #!/usr/local/bin/perl use strict; use Net::SMTP::Server; use Net::SMTP::Server::Client; $|=1; my $s = new Net::SMTP::Server('vk-dev',8025); while (my $conn = $s->accept()) { my $client = new Net::SMTP::Server::Client($conn) || die("Unable to handle client connection: $!\n"); $client->process(); print "."; } --Apple-Mail=_28465A14-1206-49C8-A6B8-CE07E76BCD1C--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?2392D9E1-CA83-42F2-A3C9-DFF63772539F>