[Vm-dev] Slow Unix socket write()s?

[David T. Lewis]

On Tue, Feb 17, 2009 at 06:38:16PM -0800, Andreas Raab wrote:
> 
> Folks -
> 
> I've been doing a bit of load-testing on our servers and thing that 
> surprised me was that even in moderate load tests the VM appears to be 
> spending some 20-30% of its total execution time in 
> Socket>>primSocket:sendData:startIndex:count:. This is roughly at a 
> throughput of 10Mbit so nothing spectacular and a long ways before we 
> hit our bandwidth limits.
> 
> Given that the primitive in the Unix VM appears to be a vanilla call to 
> write() I cannot possibly imagine what could cause this to take that 
> much time. Also, all of these sends are guarded so socketSendDone: 
> returned true prior to calling the send function (socketSendDone: takes 
> about 2% total time in the profiles).
> 
> Has anyone seen similar behavior or has an idea on how to find out what 
> is going on? If this is known write() behavior I would definitely 
> consider putting this into a pthread for our servers. It is currently by 
> far the biggest bottleneck that I can see.
> 
> Any ideas?

Put a network analyzer (http://www.wireshark.org) on it and see what's
going on at the TCP session level. There's a lot happening underneath
the write() that is not visible, including the network stack, routers,
TCP session protocol negotiation, etc. Looking through a log of the
TCP session with wireshark can give an idea of what is really happening.

If the VM is spending a lot of time blocking on writes to the network,
and you know that network throughput is not the bottleneck, it suggests
chattiness at the lower levels. This may be related to small chunks of
data being written in separate write() calls.

I'm assuming that the time is actually being spent in the write() calls.
If that is not clear, you can confirm it by profiling the VM itself
(gprof). You should positively verify this before putting effort into
moving the writes into pthreads.

Some characteristics of TCP sessions can be influenced by setting
socket options (man setsockopt, man tcp). I have not experimented with
this, but Socket>>setOption:value: can apparently be used to request
these option settings.

Try googling "tcp socket option tuning" for some more ideas.

Dave