From: =?UTF-8?B?T3phbiDDh2HEn2xheWFu?= Subject: Re: Poor KVM guest performance on an HP rack server Date: Sun, 13 Dec 2009 13:58:21 +0200 Message-ID: <4B24D6DD.8060509@pardus.org.tr> References: <4B243B2B.806@pardus.org.tr> <4B24BE52.6060703@redhat.com> <4B24D1C2.9010807@pardus.org.tr> Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: QUOTED-PRINTABLE Cc: "linux-kernel@vger.kernel.org" , KVM list To: Avi Kivity Return-path: Received: from lider.pardus.org.tr ([193.140.100.216]:33056 "HELO lider.pardus.org.tr" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with SMTP id S1752595AbZLML6U convert rfc822-to-8bit (ORCPT ); Sun, 13 Dec 2009 06:58:20 -0500 In-Reply-To: <4B24D1C2.9010807@pardus.org.tr> Sender: kvm-owner@vger.kernel.org List-ID: Ozan =C3=87a=C4=9Flayan wrote: > Avi Kivity wrote: >> First, are you sure that kvm is enabled? 'info kvm' in the monitor. > (qemu) info kvm > kvm support: enabled Resending it as my mail client wrapped all the lines, sorry.. (qemu) info kvm kvm support: enabled (qemu) info cpus * CPU #0: pc=3D0x00000000c011ceb3 (halted) thread_id=3D26023 CPU #1: pc=3D0x00000000c011ceb3 (halted) thread_id=3D26024 (qemu) info block virtio0: type=3Dhd removable=3D0 file=3D/dev/cciss/c1d0p1 ro=3D0 drv=3D= host_device encrypted=3D0 ide1-cd0: type=3Dcdrom removable=3D1 locked=3D0 [not inserted] floppy0: type=3Dfloppy removable=3D1 locked=3D0 [not inserted] sd0: type=3Dfloppy removable=3D1 locked=3D0 [not inserted] ------- KVM related messages on the host server: ~ # dmesg |grep kvm [ 3649.058945] loaded kvm module (kvm-kmod-2.6.32) [ 3683.736737] kvm: emulating exchange as write (It's interesting, what= does it mean?) On the guest side: ~ # dmesg | grep kvm [ 0.000000] kvm-clock: cpu 0, msr 0:64a3e1, boot clock [ 0.000000] kvm-clock: cpu 0, msr 0:20103e1, primary cpu clock [ 0.065075] kvm-clock: cpu 1, msr 0:20203e1, secondary cpu clock =46irst of all if there are some specific outputs that will reveal the IO/CPU boundness of the workload, I'd like to give them too. I'm not much familiar with diagnostic/analysis tools.. =46rom host's POV: ---------------- Guest is idle: PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 26117 root 20 0 2153m 175m 1356 S 5 0.5 0:33.57 qemu-kvm Guest is configuring CUPS: PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 26117 root 20 0 2129m 180m 1356 S 143 0.6 0:44.34 qemu-kvm (= peak at 140,150~ %CPU) load average reached 0.91 at the end of the configuration. SMP view of top command shows that only Cpu2 and Cpu9 are involved, other ones are zeroed (maybe coherent with -smp 2, don't have much idea= ): Cpu2 : 28.4%us, 31.4%sy, 0.0%ni, 40.2%id, 0.0%wa, 0.0%hi, 0.0%si, = 0.0%st Cpu9 : 27.7%us, 26.7%sy, 0.0%ni, 45.5%id, 0.0%wa, 0.0%hi, 0.0%si, = 0.0%st vmstat -n 1 output on host: procs -----------memory---------- ---swap-- -----io---- -system-- -----= cpu------ r b swpd free buff cache si so bi bo in cs us sy= id wa st . . . 2 0 0 30161636 117300 116416 0 0 0 36 20366 3868 2= 2 96 0 0 (./configure) 1 0 0 30161468 117300 116416 0 0 0 4 21673 4153 2= 3 95 0 0 2 0 0 30160848 117300 116416 0 0 0 0 16549 4215 2= 2 95 0 0 2 0 0 30160396 117300 116416 0 0 0 0 21089 4196 2= 3 95 0 0 1 0 0 30160308 117300 116416 0 0 0 0 17031 4189 2= 3 95 0 0 1 0 0 30160088 117300 116420 0 0 0 128 21772 4184 2= 3 95 0 0 4 0 0 30159848 117304 116416 0 0 0 28 22378 4117 2= 3 95 0 0 2 0 0 30159704 117312 116420 0 0 0 20 23530 4082 2= 3 95 0 0 1 0 0 30159624 117312 116420 0 0 0 0 20997 4098 2= 3 95 0 0 1 0 0 30159608 117324 116416 0 0 0 40 18519 4290 2= 3 95 0 0 1 0 0 30159600 117324 116416 0 0 0 76 20959 4187 2= 3 95 0 0 1 0 0 30159764 117324 116416 0 0 0 0 19718 4205 2= 3 95 0 0 1 0 0 30159848 117324 116416 0 0 0 0 19934 4095 2= 3 95 0 0 1 0 0 30159724 117324 116416 0 0 0 0 21821 4094 2= 3 95 0 0 1 0 0 30159684 117328 116412 0 0 0 16 19621 4093 2= 2 95 0 0 1 0 0 30159848 117328 116416 0 0 0 76 19630 4162 2= 3 95 0 0 1 0 0 30159724 117328 116416 0 0 0 0 22810 4033 2= 3 95 0 0 1 0 0 30159848 117328 116416 0 0 0 0 20525 4105 2= 3 95 0 0 1 0 0 30159560 117328 116416 0 0 0 0 15715 4188 2= 2 95 0 0 1 0 0 30159516 117328 116416 0 0 0 0 17686 4223 2= 2 95 0 0 1 0 0 30159476 117328 116416 0 0 0 76 17308 4174 2= 2 95 0 0 1 0 0 30159888 117328 116416 0 0 0 0 17973 4186 2= 3 95 0 0 1 0 0 30159848 117328 116416 0 0 0 0 18795 4147 2= 3 95 0 0 1 0 0 30159808 117328 116416 0 0 0 0 18346 4181 2= 2 95 0 0 1 0 0 30160096 117328 116416 0 0 0 0 17054 4202 2= 2 95 0 0 1 0 0 30159892 117328 116416 0 0 0 76 16767 4256 2= 2 95 0 0 2 0 0 30159600 117328 116416 0 0 0 8 19817 4191 2= 3 95 0 0 2 0 0 30159600 117328 116416 0 0 0 0 19709 4125 2= 3 95 0 0 1 0 0 30159476 117328 116416 0 0 0 0 17322 4153 2= 2 95 0 0 1 0 0 30159600 117328 116416 0 0 0 0 20106 4189 2= 3 95 0 0 1 0 0 30159808 117328 116416 0 0 0 80 17810 4202 2= 2 95 0 0 1 0 0 30159848 117328 116416 0 0 0 0 16723 4217 2= 2 95 0 0 1 0 0 30160052 117328 116416 0 0 0 0 17799 4140 2= 2 95 0 0 1 0 0 30159560 117328 116416 0 0 0 0 15878 4244 2= 2 95 0 0 2 0 0 30159764 117328 116416 0 0 0 0 19632 4124 2= 3 95 0 0 1 0 0 30160144 117328 116416 0 0 0 188 18119 4255 2= 2 95 0 0 1 0 0 30159860 117328 116416 0 0 0 0 17664 4139 2= 2 95 0 0 2 0 0 30159856 117328 116416 0 0 0 0 23323 4099 2= 3 95 0 0 2 0 0 30159776 117328 116416 0 0 0 12 30120 3790 2= 3 94 0 0 1 0 0 30159484 117328 116416 0 0 0 0 25599 4172 2= 3 95 0 0 2 0 0 30159732 117328 116416 0 0 0 128 41030 3579 2= 4 94 0 0 2 0 0 30159528 117328 116416 0 0 0 0 39064 3644 2= 4 94 0 0 1 0 0 30159816 117328 116416 0 0 0 0 39337 3556 2= 4 94 0 0 1 0 0 30159940 117328 116416 0 0 0 0 41252 3617 2= 4 94 0 0 2 0 0 30160112 117328 116416 0 0 0 0 36845 3668 2= 3 94 0 0 2 0 0 30160484 117328 116416 0 0 0 116 39011 3737 2= 4 94 0 0 1 0 0 30160196 117328 116416 0 0 0 0 38782 3646 2= 4 94 0 0 1 0 0 30160072 117328 116416 0 0 0 0 38546 3684 2= 4 94 0 0 1 0 0 30160444 117328 116416 0 0 0 0 37738 3641 2= 4 94 0 0 0 0 0 30160336 117328 116416 0 0 0 20 26019 3596 2= 3 95 0 0 0 0 0 30160460 117328 116416 0 0 0 184 2373 2286 0 = 0 100 0 0 (finished) 0 0 0 30160460 117328 116416 0 0 0 0 2398 2279 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2356 2251 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2395 2275 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2354 2249 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2395 2283 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2367 2230 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2396 2277 0 = 0 100 0 0 0 0 0 30160460 117328 116416 0 0 0 0 2344 2223 0 = 0 100 0 0 I also checked iotop on host and qemu-kvm appears occasionally with dis= k writes at max 200 K/s. =46rom guest's POV: ----------------- Configuring CUPS: PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 19258 root 20 0 3396 1656 1192 R 18 0.1 0:05.20 configure = (Saw maximum 22 %CPU) The following is the highest load average instant during configuration: top - 11:35:32 up 33 min, 3 users, load average: 0.56, 0.25, 0.15 Tasks: 99 total, 4 running, 95 sleeping, 0 stopped, 0 zombie Cpu0 : 4.7%us, 68.3%sy, 0.0%ni, 27.0%id, 0.0%wa, 0.0%hi, 0.0%si, = 0.0%st Cpu1 : 4.3%us, 66.3%sy, 0.0%ni, 29.3%id, 0.0%wa, 0.0%hi, 0.0%si, = 0.0%st Mem: 2061660k total, 137564k used, 1924096k free, 58672k buffer= s Swap: 307192k total, 0k used, 307192k free, 49240k cached vmstat -n 1: ------------ (context switches and interrupts are much more higher during configuration than the idle state) procs -----------memory---------- ---swap-- -----io---- -system-- -----= cpu------ r b swpd free buff cache si so bi bo in cs us sy= id wa st 0 0 0 1926012 58552 49172 0 0 27 4 165 46 1 = 8 91 0 0 0 0 0 1925956 58552 49176 0 0 0 0 33 18 0 = 0 100 0 0 0 0 0 1925832 58560 49172 0 0 0 32 71 78 0 = 0 100 0 0 0 0 0 1925832 58560 49176 0 0 0 0 42 21 0 = 0 100 0 0 0 0 0 1925832 58560 49176 0 0 0 0 74 73 0 = 1 99 0 0 0 0 0 1925832 58560 49176 0 0 0 0 26 15 0 = 0 100 0 0 0 0 0 1925832 58560 49176 0 0 0 0 95 216 0 = 0 100 0 0 0 0 0 1925832 58560 49176 0 0 0 0 33 35 0 = 0 100 0 0 0 0 0 1925832 58568 49176 0 0 0 12 143 166 1 = 0 99 0 0 0 0 0 1925840 58568 49176 0 0 0 0 181 224 0 = 1 99 0 0 0 0 0 1925880 58568 49176 0 0 0 0 67 71 0 = 0 100 0 0 0 0 0 1925880 58568 49176 0 0 0 0 22 12 0 = 0 100 0 0 2 0 0 1925880 58568 49176 0 0 0 0 108 119 0 = 0 100 0 0 0 0 0 1925624 58576 49176 0 0 0 12 222 212 1 = 4 95 0 0 0 0 0 1925540 58576 49176 0 0 0 0 220 185 0 = 2 98 0 0 0 0 0 1925500 58576 49176 0 0 0 0 34 26 0 = 0 100 0 0 0 0 0 1925508 58576 49176 0 0 0 12 164 121 0 = 1 98 0 0 0 0 0 1925508 58576 49176 0 0 0 0 54 59 0 = 0 100 0 0 0 0 0 1925508 58584 49176 0 0 0 36 81 87 0 = 0 100 0 0 0 0 0 1925508 58584 49176 0 0 0 0 47 30 0 = 1 100 0 0 0 0 0 1925508 58584 49176 0 0 0 0 77 80 0 = 0 100 0 0 0 0 0 1925508 58584 49176 0 0 0 0 71 78 0 = 0 100 0 0 0 0 0 1925436 58584 49176 0 0 0 0 175 216 0 = 0 100 0 0 0 0 0 1925428 58584 49176 0 0 0 0 80 66 0 = 1 99 0 0 0 0 0 1925428 58592 49176 0 0 0 48 84 91 0 = 0 100 0 0 1 0 0 1924788 58592 49176 0 0 0 0 1413 401 2 3= 3 65 0 0 (./configure) 1 0 0 1924092 58592 49072 0 0 0 4 2210 599 5 5= 7 38 0 0 1 0 0 1924544 58592 49080 0 0 0 0 2131 349 5 5= 1 45 0 0 1 0 0 1924580 58592 49088 0 0 0 0 2188 564 5 5= 4 42 0 0 2 0 0 1924796 58592 49092 0 0 0 0 2153 386 5 5= 3 42 0 0 2 0 0 1924892 58604 49092 0 0 0 112 2148 409 5 5= 4 41 0 0 1 0 0 1924732 58604 49096 0 0 0 0 2153 415 5 5= 6 39 0 0 1 0 0 1924916 58604 49100 0 0 0 0 2197 508 5 5= 6 39 0 0 1 0 0 1924788 58604 49100 0 0 0 0 2134 376 5 5= 6 40 0 0 1 0 0 1924612 58604 49100 0 0 0 4 2199 522 6 5= 2 42 0 0 1 0 0 1924772 58612 49100 0 0 0 84 2184 405 6 5= 3 41 0 0 3 0 0 1924960 58612 49116 0 0 0 0 2187 453 5 5= 3 42 0 0 1 0 0 1924600 58612 49112 0 0 0 0 2156 474 5 5= 4 42 0 0 1 0 0 1924164 58612 49128 0 0 0 0 2151 420 5 5= 5 40 0 0 2 0 0 1924944 58612 49116 0 0 0 0 2130 357 5 5= 3 42 0 0 2 0 0 1924536 58620 49120 0 0 0 80 2218 691 6 5= 4 41 0 0 1 0 0 1924252 58620 49144 0 0 0 0 2121 358 5 5= 4 41 0 0 1 0 0 1924888 58620 49128 0 0 0 0 2158 422 6 5= 4 41 0 0 1 0 0 1922456 58620 49132 0 0 0 0 2125 386 6 5= 0 44 0 0 1 0 0 1924696 58620 49144 0 0 0 0 2195 451 5 5= 3 43 0 0 2 0 0 1924780 58628 49140 0 0 0 80 2143 379 6 5= 1 44 0 0 2 0 0 1924660 58628 49144 0 0 0 0 2151 389 6 5= 1 44 0 0 1 0 0 1924380 58628 49144 0 0 0 0 2130 315 7 5= 0 43 0 0 1 0 0 1924504 58628 49152 0 0 0 0 2169 400 6 5= 2 42 0 0 2 0 0 1924548 58628 49156 0 0 0 0 2126 320 6 5= 1 44 0 0 1 0 0 1924660 58636 49156 0 0 0 80 2161 367 5 5= 2 43 0 0 1 0 0 1924412 58636 49160 0 0 0 8 2133 323 5 5= 2 43 0 0 1 0 0 1924392 58636 49176 0 0 0 0 2182 575 5 5= 5 40 0 0 1 0 0 1924516 58636 49180 0 0 0 0 2128 318 6 5= 2 43 0 0 1 0 0 1923572 58636 49180 0 0 0 0 2164 432 7 5= 1 43 0 0 1 0 0 1924192 58644 49184 0 0 0 80 2164 451 5 5= 2 43 0 0 1 0 0 1923980 58644 49192 0 0 0 0 2160 389 7 5= 0 44 0 0 2 0 0 1924528 58644 49192 0 0 0 0 2122 318 6 5= 1 43 0 0 2 0 0 1924448 58644 49212 0 0 0 0 2166 418 7 5= 1 43 0 0 1 0 0 1923872 58644 49200 0 0 0 72 2137 322 6 5= 2 43 0 0 1 0 0 1923276 58652 49208 0 0 0 84 2171 401 5 5= 3 42 0 0 1 0 0 1923052 58652 49220 0 0 0 0 2175 554 6 5= 4 41 0 0 1 0 0 1924736 58652 49220 0 0 0 0 2172 395 6 5= 4 40 0 0 2 0 0 1924560 58652 49100 0 0 0 4 2145 1591 6 5= 9 36 0 0 2 0 0 1924460 58652 49212 0 0 0 28 2212 573 5 6= 0 36 0 0 3 0 0 1924060 58660 49224 0 0 0 96 2201 583 5 6= 3 33 0 0 1 0 0 1924128 58660 49240 0 0 0 0 2189 611 5 6= 7 28 0 0 1 0 0 1923668 58660 49240 0 0 0 0 2169 652 6 6= 7 28 0 0 4 0 0 1924212 58660 49240 0 0 0 0 2225 705 4 6= 8 28 0 0 1 0 0 1924136 58660 49240 0 0 0 0 2158 571 5 6= 6 29 0 0 1 0 0 1924176 58672 49228 0 0 0 152 2211 693 4 6= 9 27 0 0 2 0 0 1924072 58672 49240 0 0 0 0 2169 569 5 6= 7 29 0 0 4 0 0 1924180 58672 49240 0 0 0 0 2183 620 5 6= 8 28 0 0 1 0 0 1924140 58672 49240 0 0 0 0 2208 811 4 6= 8 28 0 0 1 0 0 1924240 58672 49244 0 0 0 20 2190 606 4 6= 4 32 0 0 0 0 0 1924800 58672 49236 0 0 0 0 646 1352 3 1= 8 78 0 0 0 0 0 1924808 58684 49236 0 0 0 200 111 162 0 = 1 99 0 0 0 0 0 1924808 58684 49236 0 0 0 0 74 84 0 = 0 100 0 0 (finished) 0 0 0 1924808 58684 49236 0 0 0 0 139 170 0 = 0 100 0 0 0 0 0 1924808 58684 49236 0 0 0 0 53 67 0 = 0 99 0 0