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

[Andreas Raab]

Hi John -

Good points, but we've long given up on MessageTally and replaced it 
with our own SystemProfiler and I do really trust its results. So the 
question still stands: Why could write() possibly be so slow?

Cheers,
   - Andreas

John M McIntosh wrote:
> 
> mmm I do need to ask how do you know the measurements are correct? Well 
> assuming you  used message tally?
> 
> I noticed in some benchmarking of object file out that it was saying 20% 
> of the time in this case 24 SECONDS was taken up
> in SystemDictionary(IdentityDictionary)>>scanFor:    in looking at why 
> by adding a method to SystemDictionary and collecting information
> about the number of objects been looked for, and how many milliseconds I 
> came to the conclusion that message tally was lying, there
> was only 90 some usages, accounting for 0 milliseconds.
> 
> However I've not been able to determine why it's broken.
> System (System-adrian_lienhard.ducasse.207) btw
> 
> 
> In the past I've suggested using the message tracing VM and logging 
> information in a more meaningful way since that  hooks into the actual 
> message
> send in the VM would give exact information. Plus it would leave less 
> foot prints in the image since you aren't mixing another process (tally 
> keeping)
> into the running of the smalltalk code.
> 
> 
> On 17-Feb-09, at 6:38 PM, 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?
>>
>> Cheers,
>>  - Andreas
> 
> -- 
> ===========================================================================
> John M. McIntosh <johnmci at smalltalkconsulting.com>
> Corporate Smalltalk Consulting Ltd.  http://www.smalltalkconsulting.com
> ===========================================================================
> 
> 
>