From owner-freebsd-net@FreeBSD.ORG Sat Oct 11 19:12:40 2008 Return-Path: Delivered-To: freebsd-net@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 1451F106568A; Sat, 11 Oct 2008 19:12:40 +0000 (UTC) (envelope-from kris@FreeBSD.org) Received: from weak.local (freefall.freebsd.org [IPv6:2001:4f8:fff6::28]) by mx1.freebsd.org (Postfix) with ESMTP id 468B78FC1A; Sat, 11 Oct 2008 19:12:39 +0000 (UTC) (envelope-from kris@FreeBSD.org) Message-ID: <48F0FAC6.8040307@FreeBSD.org> Date: Sat, 11 Oct 2008 20:13:10 +0100 From: Kris Kennaway User-Agent: Thunderbird 2.0.0.17 (Macintosh/20080914) MIME-Version: 1.0 To: =?GB2312?B?x/G9ow==?= References: <000a01c9291a$b81fa560$01000001@china.huawei.com> In-Reply-To: <000a01c9291a$b81fa560$01000001@china.huawei.com> Content-Type: text/plain; charset=GB2312 Content-Transfer-Encoding: 8bit Cc: freebsd-net@freebsd.org, 'John Baldwin' Subject: Re: kernel profiling: spinlock_exit consumes 36% CPU time. X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 11 Oct 2008 19:12:40 -0000 Ηρ½£ wrote: > Many thanks for the information. > > Could we say that interrupt handlers consumed ~36% execution time? > > Is this number too high? Is it possible that we abuse the use of critical > sections in kernel? Also note that profiling itself is using ~40% of CPU. That means you need to worry about whether it is seriously skewing the results away from what they would be without profiling. If you can use hwpmc then the profiling overhead is much less. However support for modern Intel CPUs was only recently added in -CURRENT and may not have been merged to 7.x yet, so it might not be usable for you yet. If you run without profiling then top(1) will show you the CPU use of the interrupt handlers. Kris > > Looking forward to your options. Many thanks. > > Qiu Jian > > > On Tuesday 07 October 2008 07:44:00 am Ηρ½£ wrote: >> Hi, folks, >> >> I did kernel profiling when a single thread client sends UDP packets >> to a single thread server on the same machine. >> >> In the output kernel profile, the first few kernel functions that >> consumes the most CPU time are listed below: >> >> granularity: each sample hit covers 16 byte(s) for 0.01% of 25.68 >> seconds >> >> % 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 time > spent executing the handlers for any pending interrupts are attributed to > spinlock_exit(). > > -- > John Baldwin > > > _______________________________________________ > freebsd-questions@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-questions > To unsubscribe, send any mail to "freebsd-questions-unsubscribe@freebsd.org" > >