From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:40498) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X192O-000221-Ul for qemu-devel@nongnu.org; Sun, 29 Jun 2014 02:56:41 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1X192F-0002cV-RK for qemu-devel@nongnu.org; Sun, 29 Jun 2014 02:56:32 -0400 Received: from mail-wi0-x22c.google.com ([2a00:1450:400c:c05::22c]:38268) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1X192F-0002cP-Gk for qemu-devel@nongnu.org; Sun, 29 Jun 2014 02:56:23 -0400 Received: by mail-wi0-f172.google.com with SMTP id hi2so4569855wib.17 for ; Sat, 28 Jun 2014 23:56:21 -0700 (PDT) Message-ID: <53AFB893.1010105@gmail.com> Date: Sun, 29 Jun 2014 09:56:19 +0300 From: Avi Kivity MIME-Version: 1.0 References: <53AB0C7C.1050805@gmail.com> <53ABD74A.2070607@gmail.com> <53AC2EDF.5090408@gmail.com> In-Reply-To: <53AC2EDF.5090408@gmail.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Subject: Re: [Qemu-devel] memory: memory_region_transaction_commit() slow List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Etienne Martineau Cc: Paolo Bonzini , Peter Crosthwaite , gonglei , Fam , qemu-devel@nongnu.org On 06/26/2014 05:31 PM, Etienne Martineau wrote: > On 14-06-26 04:18 AM, Avi Kivity wrote: >> On 06/25/2014 08:53 PM, Etienne Martineau wrote: >>> Hi, >>> >>> It seems to me that there is a scale issue O(n) in memory_region_transaction_commit(). >> It's actually O(n^3). Flatview is kept sorted but is just a vector, so if you insert n regions, you have n^2 operations. In addition every PCI device has an address space, so we get n^3 (technically the third n is different from the first two, but they are related). >> >> The first problem can be solved by implementing Flatview with an std::set<> or equivalent, the second by memoization - most pci address spaces are equal (they only differ based on whether bus mastering is enabled or not), so a clever cache can reduce the effort to generate them. >> >> However I'm not at all sure that the problem is cpu time in qemu. It could be due to rcu_synchronize delays when the new memory maps are fed to kvm and vfio. I recommend trying to isolate exactly where the time is spent. >> > It's seem like the linear increase in CPU time comes from QEMU ( at least from my measurements below) In those code paths QEMU calls back into KVM (KVM_SET_MEMORY_REGION) and vfio. So it would be good to understand exactly where the time is spent. I doubt it's computation (which is O(n^3), but very fast), instead it's likely waiting for something. > In QEMU kvm_cpu_exec() I've added a hook that measure the time that is spent outside 'kvm_vcpu_ioctl(cpu, KVM_RUN, 0)' > From the logs below this is "QEMU long exit vCPU n x(msec) exit_reason' > > Similarly in KVM vcpu_enter_guest() I've added a new ftrace that measure the time spent outside 'kvm_x86_ops->run(vcpu)' > From the logs below this is "kvm_long_exit: x(msec)'. Please note that this is a trimmed down view of the real ftrace output. > > Also please note that the above hacks are useful ( at least to me since I haven't figured out a better way to do the same with existing ftrace ) to measure the RTT at both QEMU and KVM level. > > The time spent outside KVM 'kvm_x86_ops->run(vcpu)' will always be greater than the time spent outside QEMU 'kvm_vcpu_ioctl(cpu, KVM_RUN, 0)' for a given vCPU. Now > the difference between the time spent outside KVM to the time spend outside QEMU ( for a given vCPU ) tells us who is burning cycle ( QEMU or KVM ) and how much ( in msec ) > > In the below experiment I've put side by side the QEMU and the KVM RTT time. We can see that the time to assign device ( same BAR size for all devices ) increase > linearly ( like previously reported ). Also from the RTT measurement both QEMU and KVM are mostly within the same range suggesting that the increase comes from QEMU and not KVM. > > The one exception is that for every device assign there is a KVM operation that seems to be taking ~100msec each time. Since this is O(1) I'm not too concerned. > > > device assign #1: > device_add pci-assign,host=28:10.2,bus=pciehp.3.8 > > kvm_long_exit: 100 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 20 2 kvm_long_exit: 20 > QEMU long exit vCPU 0 20 2 kvm_long_exit: 20 > QEMU long exit vCPU 0 20 2 kvm_long_exit: 20 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 19 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 19 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 20 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 19 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 19 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 19 > QEMU long exit vCPU 0 19 2 kvm_long_exit: 20 > QEMU long exit vCPU 0 42 2 kvm_long_exit: 42 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > > device assign #2: > device_add pci-assign,host=28:10.3,bus=pciehp.3.9 > > kvm_long_exit: 101 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 21 2 kvm_long_exit: 21 > QEMU long exit vCPU 0 45 2 kvm_long_exit: 45 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > > device assign #3: > device_add pci-assign,host=28:10.4,bus=pciehp.3.10 > > kvm_long_exit: 100 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 23 2 kvm_long_exit: 23 > QEMU long exit vCPU 0 48 2 kvm_long_exit: 48 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > > device assign #4: > device_add pci-assign,host=28:10.5,bus=pciehp.3.11 > > kvm_long_exit: 100 > QEMU long exit vCPU 0 27 2 kvm_long_exit: 27 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 24 2 kvm_long_exit: 24 > QEMU long exit vCPU 0 25 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 24 2 kvm_long_exit: 24 > QEMU long exit vCPU 0 24 2 kvm_long_exit: 25 > QEMU long exit vCPU 0 52 2 kvm_long_exit: 52 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > > device assign #5: > device_add pci-assign,host=28:10.6,bus=pciehp.3.12 > > kvm_long_exit: 100 > QEMU long exit vCPU 0 28 2 kvm_long_exit: 28 > QEMU long exit vCPU 0 27 2 kvm_long_exit: 27 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 27 2 kvm_long_exit: 27 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 26 2 kvm_long_exit: 26 > QEMU long exit vCPU 0 55 2 kvm_long_exit: 56 > QEMU long exit vCPU 0 28 2 kvm_long_exit: 28 > > thanks, > Etienne >