[Adium-devl] fsync() vs. fcntl() with F_FULLSYNC (was re: [23171])

[Evan Schoenberg]

On Apr 16, 2008, at 8:52 PM, Peter Hosey wrote:

> On Apr 16, 2008, at 17:34:12, evands at adiumx.com wrote:
>> Decreasing AIXMLAppender's paranoia for a fairly significant
>> performance boost.
>
> How many seconds per message (or per chat) did this save?

Using the CHUD framework and Shark in remote monitoring mode with  
chudStartRemotePerfMonitor() at the beginning of -[AIXMLAppender  
writeData:seekBackLength:] and chudStopRemotePerfMonitor() at its end  
(patch attached), I set Shark to sample every 20 us, its minimum  
sampling slice.  I then sent a several paragraph message to myself  
such that it would be logged sending and then receiving.  The use of  
the remotePerMonitor() calls start and stop Shark's monitoring just  
for that method, allowing us to peer very closely at what is costly  
within it.

The results are fairly striking.

In both cases, write_nocancel() and ( fsync_noncancel() or  
fcntl_nocancel() ) (the latter depending upon which call is being  
used) are the most expensive parts of the writing operation.  The  
Objective C messaging is negligible by comparison.

When using fcntl([file fileDescriptor], F_FULLFSYNC, /*arg*/ 0) we  
find that write() requires between 1% and 6% of the total time.   
fcntl() uses between 89% and 96.2% of the total time. This  
corresponded to write() using between 20 and 120 us, with an average  
of 47.5 us; fcntl used between 648 and 1740 us, with an average of  
1142 us.  This is an average total time elapsed for the method of  
1189.5 us.

When using fysnc() we find that write() and fysnc() use much closer to  
the same amount of time; write does not increase by much in time  
required, and I suspect the change seen is well within statistical  
error though I didn't run any statistical anaylsis.  Write() used  
between 12% and 36% of the total time, using an average of 61 us.   
fsync() used between 36% and 55% of the time, corresponding to between  
24.2 us and 144 us, for an average of 92.8 us. This is an average  
total time elapsed for the method of 153 us.

Statistical sampling error is 19 us because Shark has a 20 us minimum  
sampling slice.

The difference in microseconds sounds huge by those numbers, and it  
does highlight the significant difference in the functions, though  
it's worth pointing out that 900 us is only 0.0009 seconds..  I  
convinced myself it felt 'snappier' with the change, and given natural  
variation of background processes it may be noticeable in normal  
usage, but an otherwise idle computer should not allow an average user  
to distinguish the change in a typical moment of messaging.  However:

These tests were performed with no other drive activity to allow them  
to be better controlled.  Because F_FULLSYNC waits for the drive's  
buffer to be fully emptied before returning, I would expect much  
larger differences if Adium weren't the only program making use of the  
drive; it was a discussion with David over using Adium in this  
situation that led to the investigation and change.



Cheers,
Evan
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://adium.im/pipermail/devel_adium.im/attachments/20080417/5ce6af28/attachment-0002.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: fsync_testing.diff
Type: application/octet-stream
Size: 7144 bytes
Desc: not available
URL: <http://adium.im/pipermail/devel_adium.im/attachments/20080417/5ce6af28/attachment.obj>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://adium.im/pipermail/devel_adium.im/attachments/20080417/5ce6af28/attachment-0003.html>