From owner-freebsd-current@FreeBSD.ORG Fri Mar 21 03:46:15 2008 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id B1339106566C for ; Fri, 21 Mar 2008 03:46:15 +0000 (UTC) (envelope-from sgk@troutmask.apl.washington.edu) Received: from troutmask.apl.washington.edu (troutmask.apl.washington.edu [128.208.78.105]) by mx1.freebsd.org (Postfix) with ESMTP id 71E928FC15 for ; Fri, 21 Mar 2008 03:46:15 +0000 (UTC) (envelope-from sgk@troutmask.apl.washington.edu) Received: from troutmask.apl.washington.edu (localhost [127.0.0.1]) by troutmask.apl.washington.edu (8.14.2/8.14.2) with ESMTP id m2L3jG1x098837 for ; Thu, 20 Mar 2008 20:45:16 -0700 (PDT) (envelope-from sgk@troutmask.apl.washington.edu) Received: (from sgk@localhost) by troutmask.apl.washington.edu (8.14.2/8.14.2/Submit) id m2L3jGps098836 for freebsd-current@freebsd.org; Thu, 20 Mar 2008 20:45:16 -0700 (PDT) (envelope-from sgk) Date: Thu, 20 Mar 2008 20:45:16 -0700 From: Steve Kargl To: freebsd-current@freebsd.org Message-ID: <20080321034516.GA98780@troutmask.apl.washington.edu> References: <20080321030254.GA98444@troutmask.apl.washington.edu> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20080321030254.GA98444@troutmask.apl.washington.edu> User-Agent: Mutt/1.4.2.3i Subject: Re: Extremely slooooow __sys_ftruncate? X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 21 Mar 2008 03:46:15 -0000 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. 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 #include #include #include 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