From owner-freebsd-current@FreeBSD.ORG Fri Mar 21 13:33:56 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 6B1BC106566C for ; Fri, 21 Mar 2008 13:33:56 +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 3862A8FC13 for ; Fri, 21 Mar 2008 13:33:56 +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 m2LDWnbT009779; Fri, 21 Mar 2008 06:32:49 -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 m2LDWnhi009778; Fri, 21 Mar 2008 06:32:49 -0700 (PDT) (envelope-from sgk) Date: Fri, 21 Mar 2008 06:32:49 -0700 From: Steve Kargl To: Jeff Roberson Message-ID: <20080321133249.GA8586@troutmask.apl.washington.edu> References: <20080321030254.GA98444@troutmask.apl.washington.edu> <20080321034516.GA98780@troutmask.apl.washington.edu> <20080320185743.L910@desktop> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20080320185743.L910@desktop> User-Agent: Mutt/1.4.2.3i Cc: freebsd-current@freebsd.org 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 13:33:56 -0000 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