Date: Sat, 11 Oct 2008 20:13:10 +0100 From: Kris Kennaway <kris@FreeBSD.org> To: =?GB2312?B?x/G9ow==?= <qj@huawei.com> Cc: freebsd-net@freebsd.org, 'John Baldwin' <jhb@freebsd.org> Subject: Re: kernel profiling: spinlock_exit consumes 36% CPU time. Message-ID: <48F0FAC6.8040307@FreeBSD.org> In-Reply-To: <000a01c9291a$b81fa560$01000001@china.huawei.com> References: <000a01c9291a$b81fa560$01000001@china.huawei.com>
next in thread | previous in thread | raw e-mail | index | archive | help
Ηρ½£ 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" > >
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?48F0FAC6.8040307>