From owner-freebsd-current@FreeBSD.ORG Fri Dec 10 23:52:16 2010 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 CBF62106564A; Fri, 10 Dec 2010 23:52:16 +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 A7A088FC14; Fri, 10 Dec 2010 23:52:16 +0000 (UTC) Received: from troutmask.apl.washington.edu (localhost.apl.washington.edu [127.0.0.1]) by troutmask.apl.washington.edu (8.14.4/8.14.4) with ESMTP id oBANqGJh028201; Fri, 10 Dec 2010 15:52:16 -0800 (PST) (envelope-from sgk@troutmask.apl.washington.edu) Received: (from sgk@localhost) by troutmask.apl.washington.edu (8.14.4/8.14.4/Submit) id oBANqGnV028200; Fri, 10 Dec 2010 15:52:16 -0800 (PST) (envelope-from sgk) Date: Fri, 10 Dec 2010 15:52:16 -0800 From: Steve Kargl To: Alexander Motin Message-ID: <20101210235216.GA28190@troutmask.apl.washington.edu> References: <20101205231829.GA68156@troutmask.apl.washington.edu> <201012060944.03196.jhb@freebsd.org> <20101206163830.GA53157@troutmask.apl.washington.edu> <201012061301.13647.jhb@freebsd.org> <4CFD2A5B.1030006@freebsd.org> <20101206184309.GB38739@troutmask.apl.washington.edu> <4CFD2F77.8020409@freebsd.org> <20101206184949.GA39028@troutmask.apl.washington.edu> <4CFD32E6.7040003@FreeBSD.org> Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <4CFD32E6.7040003@FreeBSD.org> User-Agent: Mutt/1.4.2.3i Cc: freebsd-current@FreeBSD.org, John Baldwin , Andriy Gapon Subject: Re: Process accounting/timing has broken recently 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, 10 Dec 2010 23:52:16 -0000 On Mon, Dec 06, 2010 at 09:00:54PM +0200, Alexander Motin wrote: > On 06.12.2010 20:49, Steve Kargl wrote: > >On Mon, Dec 06, 2010 at 08:46:15PM +0200, Andriy Gapon wrote: > >>on 06/12/2010 20:43 Steve Kargl said the following: > >>>The 7-10 days is an estimate. I upgraded world/kernel on > >>>Saturday. The previous world/kernel could have been older > >>>than I'm guessing. It could be upto 4 weeks old because > >>>my laptop tends to lag behind the upgrades to my servers. > >> > >>I see. > >> > >>>I would normally use gprof to measure execution times > >>>for the functions I'm writing, but in some quick > >>>testing last night gprof appears to be broken. I'm > >>>seeing a larger variation that I would expect in > >>>self-seconds for the accumulated time for execution > >>>of expf. > >> > >>Just guessing - could you try setting sysctl kern.eventtimer.periodic=1 > >>if it's > >>not 1 already? > >> > >>And cc-ing Alexander, just in case. > > > >Thanks for the suggestion. I'll try this tonight (I left the > >laptop at home) and will report back here. > > Unless your application utilizes all CPUs all the time, you can also try > to set sysctl kern.eventtimer.idletick=1. > To follow-up on the effect these tunables, I have the following results for my application: kern.eventtimer.idletick=0 kern.eventtimer.periodic=0 139.39 real 78.34 user 60.62 sys 138.70 real 79.26 user 59.01 sys 138.99 real 78.54 user 60.03 sys 139.04 real 78.96 user 59.65 sys 139.25 real 77.65 user 61.17 sys 138.95 real 79.07 user 59.45 sys 139.00 real 78.85 user 59.72 sys 139.04 real 78.32 user 60.29 sys 138.96 real 78.49 user 60.05 sys 138.97 real 78.24 user 60.31 sys kern.eventtimer.idletick=1 kern.eventtimer.periodic=0 137.79 real 85.32 user 52.04 sys 137.67 real 84.08 user 53.16 sys 137.59 real 84.24 user 52.93 sys 137.58 real 84.50 user 52.65 sys 137.21 real 85.81 user 50.97 sys 137.84 real 84.14 user 53.27 sys 137.41 real 84.32 user 52.67 sys 137.74 real 83.00 user 54.32 sys 137.34 real 84.15 user 52.76 sys 137.82 real 83.83 user 53.57 sys kern.eventtimer.idletick=1 kern.eventtimer.periodic=1 138.35 real 98.02 user 39.89 sys 138.14 real 98.29 user 39.43 sys 138.62 real 98.17 user 40.01 sys 138.62 real 97.69 user 40.51 sys 138.39 real 97.83 user 40.14 sys 138.77 real 97.28 user 41.07 sys 138.51 real 97.89 user 40.19 sys 138.23 real 97.46 user 40.35 sys 138.53 real 97.34 user 40.77 sys 138.90 real 97.27 user 41.20 sys kern.eventtimer.idletick=0 kern.eventtimer.periodic=1 138.93 real 98.23 user 40.26 sys 138.74 real 97.45 user 40.87 sys 138.55 real 98.33 user 39.80 sys 138.50 real 98.57 user 39.50 sys 138.22 real 96.45 user 41.35 sys 138.41 real 98.05 user 39.93 sys 138.58 real 98.14 user 40.01 sys 138.80 real 97.25 user 41.12 sys 138.62 real 97.01 user 41.17 sys 138.51 real 96.98 user 41.10 sys In the end, I'll go with jhb's explanation that getrusage is not robust when it comes to accounting for user time versus system time. I'll have to devise some other method for monitoring execution speed of the functions I'm writing. -- Steve