From mboxrd@z Thu Jan 1 00:00:00 1970 From: Avi Kivity Subject: Re: high load with usb device Date: Tue, 14 Sep 2010 18:37:29 +0200 Message-ID: <4C8FA4C9.2080208@redhat.com> 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> <4C8FA2D6.1090604@msgid.tls.msk.ru> Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: KVM list To: Michael Tokarev Return-path: Received: from mx1.redhat.com ([209.132.183.28]:65360 "EHLO mx1.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752671Ab0INQhf (ORCPT ); Tue, 14 Sep 2010 12:37:35 -0400 In-Reply-To: <4C8FA2D6.1090604@msgid.tls.msk.ru> Sender: kvm-owner@vger.kernel.org List-ID: On 09/14/2010 06:29 PM, Michael Tokarev wrote: > 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). No more writes, and read() is cut to twice select() (due to the need to see a 0, we can probably elimate it if we know it's a real eventfd), somewhat fewer select()s. What's the cpu load? > 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). That time includes guest sleep time, not just cpu time, so it isn't an indicator. > 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()) > > I guess it only saw a single ioctl, so it didn't measure it. Ping the guest and you'll see ioctl times surge back. -- error compiling committee.c: too many arguments to function