From mboxrd@z Thu Jan 1 00:00:00 1970 From: Michael Tokarev Subject: Re: high load with usb device Date: Tue, 14 Sep 2010 20:29:10 +0400 Message-ID: <4C8FA2D6.1090604@msgid.tls.msk.ru> References: <4C80E839.50604@msgid.tls.msk.ru> <4C8A1AE3.8030705@redhat.com> <4C8A2187.1020202@msgid.tls.msk.ru> <4C8A59FE.9090400@msgid.tls.msk.ru> <4C8C9CAA.9030203@redhat.com> <4C8F1B54.60604@msgid.tls.msk.ru> <4C8F3B00.3000703@redhat.com> <4C8F3BA7.7060302@redhat.com> <4C8F47A1.4030600@msgid.tls.msk.ru> <4C8F497C.7000904@redhat.com> <4C8F4DA8.50606@msgid.tls.msk.ru> <4C8F50E1.3060704@redhat.com> <4C8F563E.6070701@msgid.tls.msk.ru> <4C8F757D.1010509@msgid.tls.msk.ru> <4C8F77C1.90509@redhat.com> <4C8F78D6.2060808@msgid.tls.msk.ru> <4C8F8AA2.90403@redhat.com> <4C8F8C5A.9000003@msgid.tls.msk.ru> <4C8F9C23.4090400@redhat.com> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: KVM list To: Avi Kivity Return-path: Received: from isrv.corpit.ru ([86.62.121.231]:51780 "EHLO isrv.corpit.ru" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751581Ab0INQ3N (ORCPT ); Tue, 14 Sep 2010 12:29:13 -0400 In-Reply-To: <4C8F9C23.4090400@redhat.com> Sender: kvm-owner@vger.kernel.org List-ID: 14.09.2010 20:00, Avi Kivity wrote: >> As I mentioned in other emails in this thread: >> >> o yes, I do have CONFIG_EVENTFD set, and it is being used >> too (fd#12 in the above strace). > > I thought that was the signalfd. Uh. Yes, it was, i confused the two. And yes, CONFIG_EVENTFD is set and used too. $ grep FD= config-host.mak CONFIG_EVENTFD=y CONFIG_SIGNALFD=y >> o 0.13.0-rc1 behaves the same way (that is, it also shows >> high load when idle -- the same 18% of host CPU), but it >> has no pipe on fd#5. > > I think it's host_alarm_handler()'s use of qemu_notify_event(). It's > telling the main loop to rescan pending events, even though it's called > from the main loop itself. Please drop it and rerun. Without qemu_notify_event() in host_alarm_handler(): % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 98.96 48.184832 13747 3505 ioctl 0.39 0.191613 25 7745 28 futex 0.37 0.181032 1 173192 select 0.09 0.045379 0 980369 clock_gettime 0.05 0.024362 0 351024 173220 read 0.05 0.023247 0 487766 gettimeofday 0.04 0.017996 0 319428 timer_gettime 0.03 0.013837 0 198267 timer_settime 0.02 0.010036 0 177790 rt_sigaction 0.00 0.000000 0 1 writev 0.00 0.000000 0 2 poll 0.00 0.000000 0 1 rt_sigpending 0.00 0.000000 0 1 1 rt_sigtimedwait ------ ----------- ----------- --------- --------- ---------------- 100.00 48.692334 2699091 173249 total The picture is pretty similar to the one before :) (And yes, I'm sure I've run the right binary). But it looks like we're barking the wrong tree. It's spending 99% time in ioctl. Yes, there's quite large amount of reads and gettimes, but they're taking very small time, even combined. It is still spending much more time in the ioctl (apparently in kvm_run). For comparison, here's the same strace stats without -usbdevice: % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 97.70 0.080237 22 3584 select 1.09 0.000895 0 6018 3584 read 0.33 0.000271 0 9670 clock_gettime 0.31 0.000254 0 6086 gettimeofday 0.26 0.000210 0 2432 rt_sigaction 0.17 0.000137 0 3653 timer_gettime 0.15 0.000122 0 2778 timer_settime 0.00 0.000000 0 1 ioctl 0.00 0.000000 0 1 rt_sigpending 0.00 0.000000 0 1 1 rt_sigtimedwait ------ ----------- ----------- --------- --------- ---------------- 100.00 0.082126 34224 3585 total Yes, it is still doing lots of unnecessary stuff, but the load is <1%. (This is without host_alarm_handler() in qemu_notify_event()) /mjt