250x slowdown on localhost sockets with certain sized write(2) call from perl

[Vick Khera]

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


-------------- next part --------------
A non-text attachment was scrubbed...
Name: perl-sink
Type: application/octet-stream
Size: 324 bytes
Desc: not available
URL: <http://lists.freebsd.org/pipermail/freebsd-net/attachments/20160107/83c6e11b/attachment.obj>