From owner-cvs-all Mon Sep 16 2:59:32 2002 Delivered-To: cvs-all@freebsd.org Received: from mx1.FreeBSD.org (mx1.FreeBSD.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 9CA6337B40E; Mon, 16 Sep 2002 02:59:24 -0700 (PDT) Received: from mailman.zeta.org.au (mailman.zeta.org.au [203.26.10.16]) by mx1.FreeBSD.org (Postfix) with ESMTP id E5E2343E4A; Mon, 16 Sep 2002 02:59:22 -0700 (PDT) (envelope-from bde@zeta.org.au) Received: from bde.zeta.org.au (bde.zeta.org.au [203.2.228.102]) by mailman.zeta.org.au (8.9.3/8.8.7) with ESMTP id TAA30983; Mon, 16 Sep 2002 19:59:19 +1000 Date: Mon, 16 Sep 2002 20:07:40 +1000 (EST) From: Bruce Evans X-X-Sender: bde@gamplex.bde.org To: Josef Karthauser Cc: "David O'Brien" , Poul-Henning Kamp , , Subject: Re: cvs commit: src/sys/kern kern_timeout.c In-Reply-To: <20020916084033.GB3565@genius.tao.org.uk> Message-ID: <20020916195344.S6593-100000@gamplex.bde.org> MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: owner-cvs-all@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG On Mon, 16 Sep 2002, Josef Karthauser wrote: > On Sun, Sep 15, 2002 at 07:53:09PM -0700, David O'Brien wrote: > > On Wed, Sep 04, 2002 at 01:05:00PM -0700, Poul-Henning Kamp wrote: > > > phk 2002/09/04 13:05:00 PDT > > > > > > Modified files: > > > sys/kern kern_timeout.c > > > Log: > > > Under DIAGNOSTIC, complain if a timeout(9) routine took more than 1msec. > > > > > > Revision Changes Path > > > 1.73 +23 -4 src/sys/kern/kern_timeout.c > > > http://cvsweb.freebsd.org/src/sys/kern/kern_timeout.c.diff?r1=1.72&r2=1.73 > > > > I assume you wanted this output for something. Here is the first 10 and > > last 2 of the 4468 I got after booting only 6 minutes. > > > > Sep 15 19:40:26 kernel: Expensive timeout(9) function: 0xc65dfc80(0xc659f000) 0.008711721 > > Sep 15 19:40:26 kernel: Expensive timeout(9) function: 0xc65dfc80(0xc659f000) 0.001068850 This is hard to interpret without the function names (or a full stack trace). I get these on an old dual Celeron system mainly for fxp_tick() and uma_timeout(). fxp_tick() almost always causes one under load, with an average of about 2 msec and a maximum of about 8 msec. 8 msec is a huge bite out of the 10 msec between softclock for the default HZ, and huger for larger HZ. softclock() expects to run multiple timeout routines and shouldn't take more than 1% of the CPU(s) altogether, but 8 msec per second is already 0.8% of 1 CPU for just 1 device. fxp_tick() holds Giant throughout. I think most of the time is spent in mii_tick(), and the overhead is not much larger than in RELENG_4. In theory, running with Giant held is no worse than running at splsoftclock() in RELENG_4, but in practice most interrupt handlers wait for Giant, so the low priority fxp_tick() timeout routine blocks many high priority interrupts. > The USB ethernet subsystem is guilty as hell of this... :(. Lots of the kernel is guilty of running with Giant held. The really bad places hold it for longer. Bruce To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe cvs-all" in the body of the message