Extremely slooooow __sys_ftruncate?
Jeff Roberson
jroberson at chesapeake.net
Thu Mar 20 21:59:38 PDT 2008
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. :/
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?
Thanks,
Jeff
>
> cc -o z -O -pg -static a.c
> time ./z
> 239.96 real 0.08 user 8.12 sys
>
>
> % cumulative self self total
> time seconds seconds calls ms/call ms/call name
> 81.4 6.58 6.58 51830 0.13 0.13 _ftruncate [3]
> 17.1 7.96 1.38 52056 0.03 0.03 _write [4]
> 0.7 8.01 0.05 0 100.00% .mcount (46)
> 0.6 8.05 0.05 51830 0.00 0.00 __sys_lseek [5]
> 0.1 8.06 0.01 1 7.51 7.51 fstat [9]
> 0.1 8.07 0.01 1 7.51 8027.03 main [1]
> 0.1 8.07 0.00 51830 0.00 0.00 lseek [13]
>
> Hmmm, ftruncate() mapped to _ftruncate :-/
>
> Here's the program
>
> #include <sys/stat.h>
> #include <stdio.h>
> #include <unistd.h>
> #include <fcntl.h>
>
>
> int
> main(void) {
>
> int fd, off, i, j;
>
> fd = open("junk", O_RDWR | O_CREAT, S_IRUSR | S_IWUSR);
> off = 0;
> for (i = 0; i < 5183; i++) {
> if (i%23 == 0) printf("i = %d\n", i);
> for (j = 0; j < 10; j++) {
> write(fd, &off, sizeof(off));
> off++;
> lseek(fd, off, SEEK_SET);
> ftruncate(fd, off);
> }
> }
> return 0;
> }
>
> --
> Steve
> _______________________________________________
> freebsd-current at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscribe at freebsd.org"
>
More information about the freebsd-current
mailing list