From owner-freebsd-questions@FreeBSD.ORG  Tue Oct  7 14:04:17 2008
Return-Path: <owner-freebsd-questions@FreeBSD.ORG>
Delivered-To: freebsd-questions@freebsd.org
Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34])
	by hub.freebsd.org (Postfix) with ESMTP id 841F51065695;
	Tue,  7 Oct 2008 14:04:17 +0000 (UTC) (envelope-from jhb@freebsd.org)
Received: from server.baldwin.cx (bigknife-pt.tunnel.tserv9.chi1.ipv6.he.net
	[IPv6:2001:470:1f10:75::2])
	by mx1.freebsd.org (Postfix) with ESMTP id 060658FC08;
	Tue,  7 Oct 2008 14:04:16 +0000 (UTC) (envelope-from jhb@freebsd.org)
Received: from localhost.corp.yahoo.com (john@localhost [IPv6:::1])
	(authenticated bits=0)
	by server.baldwin.cx (8.14.2/8.14.2) with ESMTP id m97E4AvC042408;
	Tue, 7 Oct 2008 10:04:10 -0400 (EDT) (envelope-from jhb@freebsd.org)
From: John Baldwin <jhb@freebsd.org>
To: freebsd-threads@freebsd.org
Date: Tue, 7 Oct 2008 09:38:04 -0400
User-Agent: KMail/1.9.7
References: <004001c92871$fdec0a10$01000001@china.huawei.com>
In-Reply-To: <004001c92871$fdec0a10$01000001@china.huawei.com>
MIME-Version: 1.0
Content-Disposition: inline
Message-Id: <200810070938.04673.jhb@freebsd.org>
Content-Type: text/plain;
  charset="gb2312"
Content-Transfer-Encoding: quoted-printable
X-Greylist: Sender succeeded SMTP AUTH authentication, not delayed by
	milter-greylist-2.0.2 (server.baldwin.cx [IPv6:::1]);
	Tue, 07 Oct 2008 10:04:10 -0400 (EDT)
X-Virus-Scanned: ClamAV 0.93.1/8384/Tue Oct 7 06:37:18 2008 on
	server.baldwin.cx
X-Virus-Status: Clean
X-Spam-Status: No, score=-2.6 required=4.2 tests=AWL,BAYES_00,NO_RELAYS 
	autolearn=ham version=3.1.3
X-Spam-Checker-Version: SpamAssassin 3.1.3 (2006-06-01) on server.baldwin.cx
Cc: =?gb2312?q?=C7=F1=BD=A3?= <qj@huawei.com>, freebsd-net@freebsd.org,
	freebsd-questions@freebsd.org
Subject: Re: kernel profiling: spinlock_exit consumes 36% CPU time.
X-BeenThere: freebsd-questions@freebsd.org
X-Mailman-Version: 2.1.5
Precedence: list
List-Id: User questions <freebsd-questions.freebsd.org>
List-Unsubscribe: <http://lists.freebsd.org/mailman/listinfo/freebsd-questions>, 
	<mailto:freebsd-questions-request@freebsd.org?subject=unsubscribe>
List-Archive: <http://lists.freebsd.org/pipermail/freebsd-questions>
List-Post: <mailto:freebsd-questions@freebsd.org>
List-Help: <mailto:freebsd-questions-request@freebsd.org?subject=help>
List-Subscribe: <http://lists.freebsd.org/mailman/listinfo/freebsd-questions>, 
	<mailto:freebsd-questions-request@freebsd.org?subject=subscribe>
X-List-Received-Date: Tue, 07 Oct 2008 14:04:17 -0000

On Tuesday 07 October 2008 07:44:00 am =C7=F1=BD=A3 wrote:
> Hi, folks,
> =20
> I did kernel profiling when a single thread client sends UDP packets to a
> single thread server on the same machine.
> =20
> In the output kernel profile, the first few kernel functions that consumes
> the most CPU time are listed below:
> =20
> granularity: each sample hit covers 16 byte(s) for 0.01% of 25.68 seconds
>=20
>   %   cumulative   self              self     total
>  time   seconds   seconds    calls  ms/call  ms/call  name
>  42.4      10.88    10.88        0  100.00%           __mcount [1]
>  36.1      20.14     9.26 17937541     0.00     0.00  spinlock_exit [4]
>   4.2      21.22     1.08  3145728     0.00     0.00  in_cksum_skip [40]
>   1.8      21.68     0.45  7351987     0.00     0.00  generic_copyin [43]
>   1.1      21.96     0.29  3146028     0.00     0.00  generic_copyout [48]
>   1.0      22.21     0.24  2108904     0.00     0.00  Xint0x80_syscall [3]
>   0.8      22.42     0.21  6292131     0.00     0.00  uma_zalloc_arg [46]
>   0.8      22.62     0.20  1048576     0.00     0.00  soreceive_generic [=
9]
>
> It is very strange that spinlock_exit consumes over 36% CPU time while it
> seems a very simple function.

It's because the intr_restore() re-enables interrupts and the resulting tim=
e=20
spent executing the handlers for any pending interrupts are attributed to=20
spinlock_exit().

=2D-=20
John Baldwin