Re: Extremely slooooow __sys_ftruncate?

From: Steve Kargl <sgk_at_troutmask.apl.washington.edu>
Date: Fri, 21 Mar 2008 06:32:49 -0700
On Thu, Mar 20, 2008 at 07:00:37PM -1000, Jeff Roberson wrote:
> On Thu, 20 Mar 2008, Steve Kargl wrote:
> 
> >On Thu, Mar 20, 2008 at 08:02:54PM -0700, Steve Kargl wrote:
> >>In the process of helping to debug a problem with gcc-4.4.0
> >>(actually a gfortran problem), I run gprof on the executable.
> >>The profile shows that __sys_ftruncate is extremely slow.
> >>
> >>  %   cumulative   self              self     total
> >> time   seconds   seconds    calls  ms/call  ms/call  name
> >> 85.6       6.05     6.05    51830     0.12     0.12  __sys_ftruncate [2]
> >>  5.6       6.44     0.40        0  100.00%           .mcount (101)
> >>  1.7       6.56     0.12    51872     0.00     0.00  _lseek [5]
> >>  1.6       6.67     0.11    52055     0.00     0.00  sigprocmask [6]
> >>  0.8       6.73     0.06   103687     0.00     0.00  memset [14]
> >>  0.4       6.76     0.03      488     0.06     0.06  __sys_write [18]
> >>  0.4       6.79     0.03        0  100.00%           
> >>  formatted_transfer_scalar
> >>
> >>time ./z
> >>     184.21 real         0.98 user         6.57 sys
> >>
> >>This program should finish well under 184 seconds.  The same program
> >>and exact same gcc/gfortran source on linux shows
> >> real    0m0.555s    user    0m0.103s    sys     0m0.452s
> >>
> >>Is __sys_ftruncate known to have performance problems?
> >>
> >
> >Well, I tried to kludge together a C example based on the
> >the Fortran test code and gfortran runtime library.
> 
> Thanks for the test code.  truncate is only handled by softupdates when 
> it's a truncate to 0.  Otherwise it's synchronous. :/

Oh. :(

> I would argue that the program is doing something terrible.  However, we 
> also shouldn't be so slow.
> 
> I'm confused by your example however.  For each iteration we're writing 4 
> bytes and then truncating 3 of them off?  Is that right?  Is that what the 
> compiler is actually doing?

This problem is associated with how gfortran has implemented the Fortran
2003 Stream I/O feature.  gfortran uses essentially a double-buffering
scheme within its IO system to accommodate all of the supported operating
systems.  Because of this scheme it has been difficult for me to trace 
through the code.  I tried to write as short as possible example C program
that touches write, lseek, and ftruncate to see the problem in one particular
code path.

Now that I know ftruncate is so slow, I may be able to work around its
use in gfortran's runtime library.

PS: Thanks for all of your recent changes in ULE and cpu affinity.

-- 
Steve
Received on Fri Mar 21 2008 - 12:33:56 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:29 UTC