[ kvm-Bugs-2494730 ] Guests "stalling" on kvm-82 / Linux 2.6.28

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Bugs item #2494730, was opened at 2009-01-09 09:59
Message generated for change (Comment added) made by kmshanah
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=893831&aid=2494730&group_id=180599

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: None
Group: None
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Kevin Shanahan (kmshanah)
Assigned to: Nobody/Anonymous (nobody)
Summary: Guests "stalling" on kvm-82 / Linux 2.6.28

Initial Comment:
I am seeing periodic stalls in Linux and Windows guests with kvm-82 on an IBM X3550 server with 2 x Xeon 5130 CPUs and 32GB RAM.

I am *reasonably* certain that this is a regression somewhere between kvm-72 and kvm-82. We had been running kvm-72 (actually, the debian kvm-source package) up until now and never noticed the problem. Now the stalls are very obvious. When the guest stalls, the at least one kvm process on the host gobbles up 100% CPU. I'll do my debugging with the Linux guest, as that's sure to be easier to deal with.

As a simple demostration that the guest is unresponsive, here is the result of me pinging the guest from another machine on the (very quiet) LAN:

--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599659ms
rtt min/avg/max/mdev = 0.255/181.211/6291.871/558.706 ms, pipe 7

The latency varies pretty badly, with spikes up to several seconds as you can see.

The problem is not reproducable on other VT capable hardware that I have - e.g. my desktop has a E8400 CPU which runs the VMs just fine. Does knowing that make it any easier to guess where the problem might be?

The Xeon 5130 does not have the "smx", "est", "sse4_1", "xsave", "vnmi" and "flexpriority" CPU flags that the E8400 does.

Because this server is the only hardware I have which exhibits the problem and it's a production machine, I have limited times where I can do testing. However, I will try confirm that kvm-72 is okay and then bisect.

Currently the host is running a 2.6.28 kernel with the kvm-82 modules. I guess I'm likely to have problems compiling the older kvm releases against this kernel, so I'll have to drop back to 2.6.27.something to run the tests.

CPU Vendor: Intel
CPU Type: Xeon 5130
Number of CPUs: 2
Host distribution: Debain Lenny/Sid
KVM version: kvm-82
Host kernel: Linux 2.6.28 x86_64
Guest Distribution: Debian Etch
Guest kernel: Linux 2.6.27.10 i686

Host's /proc/cpuinfo:

processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 15
model name      : Intel(R) Xeon(R) CPU            5130  @ 2.00GHz
stepping        : 6
cpu MHz         : 1995.117
cache size      : 4096 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 10
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni dtes64 monitor ds_cpl vmx tm2 ssse3 cx16 xtpr pdcm dca lahf_lm tpr_shadow
bogomips        : 3990.23
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 1
vendor_id       : GenuineIntel
cpu family      : 6
model           : 15
model name      : Intel(R) Xeon(R) CPU            5130  @ 2.00GHz
stepping        : 6
cpu MHz         : 1995.117
cache size      : 4096 KB
physical id     : 0
siblings        : 2
core id         : 1
cpu cores       : 2
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 10
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni dtes64 monitor ds_cpl vmx tm2 ssse3 cx16 xtpr pdcm dca lahf_lm tpr_shadow
bogomips        : 3989.96
clflush size    : 64
cache_alignment : 64
address sizes   : 36 bits physical, 48 bits virtual
power management:

processor       : 2
vendor_id       : GenuineIntel
cpu family      : 6
model           : 15
model name      : Intel(R) Xeon(R) CPU            5130  @ 2.00GHz
stepping        : 6
cpu MHz         : 1995.117
cache size      : 4096 KB
physical id     : 3
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 6
initial apicid  : 6
fpu             : yes
fpu_exception   : yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni dtes64 monitor ds_cpl vmx tm2 ssse3 cx16 xtpr pdcm dca lahf_lm tpr_shadow
bogomips	: 3990.01
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

processor	: 3
vendor_id	: GenuineIntel
cpu family	: 6
model		: 15
model name	: Intel(R) Xeon(R) CPU            5130  @ 2.00GHz
stepping	: 6
cpu MHz		: 1995.117
cache size	: 4096 KB
physical id	: 3
siblings	: 2
core id		: 1
cpu cores	: 2
apicid		: 7
initial apicid	: 7
fpu		: yes
fpu_exception	: yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni dtes64 monitor ds_cpl vmx tm2 ssse3 cx16 xtpr pdcm dca lahf_lm tpr_shadow
bogomips	: 3990.01
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:


----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2010-11-30 14:22

Message:
Hi Jes, I spent a ton of time testing this previously and I believe the
problem still exists, but I no longer have time to do these kind of tests.
See https://bugzilla.kernel.org/show_bug.cgi?id=12465 for further info.


----------------------------------------------------------------------

Comment By: Jes Sorensen (jessorensen)
Date: 2010-11-26 18:43

Message:
Hi,

I noticed this bug has been sitting idle for a long time - are you still
seeing these problems, or can we close it?

Thanks,
Jes


----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2009-01-17 21:56

Message:
Okay, git bisect on the host kernel points to the commit below as the
problem. I'll file a bug on bugzilla.kernel.org and see what they say.

14800984706bf6936bbec5187f736e928be5c218 is first bad commit
commit 14800984706bf6936bbec5187f736e928be5c218
Author: Mike Galbraith <efault@xxxxxx>
Date:   Fri Nov 7 15:26:50 2008 +0100

    sched: fine-tune SD_MC_INIT
    
    Tune SD_MC_INIT the same way as SD_CPU_INIT:
    unset SD_BALANCE_NEWIDLE, and set SD_WAKE_BALANCE.
    
    This improves vmark by 5%:
    
    vmark         132102 125968 125497 messages/sec    avg 127855.66   
.984
    vmark         139404 131719 131272 messages/sec    avg 134131.66  
1.033
    
    Signed-off-by: Mike Galbraith <efault@xxxxxx>
    Acked-by: Peter Zijlstra <a.p.zijlstra@xxxxxxxxx>
    Signed-off-by: Ingo Molnar <mingo@xxxxxxx>
    
     # *DOCUMENTATION*

:040000 040000 33b285285748415ddbb5b3dc947a70d9e7cafc94
f70fac391f313b567179b4de24fb3808d057ff87 M	include


----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2009-01-12 11:17

Message:
Another update - I've done some more testing with different host kernel
versions and kvm versions. It may be that this bug is not dependant on the
kvm version, but the host kernel. It seems that I get the guest stalls when
2.6.28 is the host kernel (with kvm-82 userspace and modules), but stepping
back to 2.6.27.10 (but still kvm-82 userspace and modules) I am unable to
trigger the problem as yet.

If things are still looking good on 2.6.27.10 by the end of the day, I'll
start a git bisect on the host kernel. I can probably only get one or two
compile/test cycles done per day, but hopefully I'll get to the bottom of
this by the end of the week.


----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2009-01-09 23:04

Message:
Hopefully this is okay - I sat watching the ping output in one terminal and
when I noticed the delays showing up I ran vmstat -1 a couple of times in
another terminal. As best I can tell I got it to run during the period with
the stalled packets, but it doesn't feel like a very precise way of doing
it.

Here's three examples - each shows the ping output around the time of the
stall(s) and the 'vmstat -1' output below each should coincide with the
time when the stalls were occurring.

64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=455 ttl=64
time=0.532 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=456 ttl=64
time=0.546 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=457 ttl=64
time=0.536 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=458 ttl=64
time=0.564 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=459 ttl=64
time=3870 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=460 ttl=64
time=2862 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=461 ttl=64
time=1854 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=462 ttl=64
time=846 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=463 ttl=64
time=0.519 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=464 ttl=64
time=0.285 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=465 ttl=64
time=0.526 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=466 ttl=64
time=0.514 ms

Fri Jan  9 22:51:46 CST 2009
efer_reload                   36         0
exits                  254320392     38515
fpu_reload              10447942      3010
halt_exits              14380628      3056
halt_wakeup              2974535       794
host_state_reload       59721044     12192
hypercalls                 86694        20
insn_emulation          20950110      5688
insn_emulation_fail          439         0
invlpg                  10240323      2736
io_exits               100781188     12198
irq_exits                1101409       818
irq_injections          18151357      5237
irq_window               3000109      1857
kvm_request_irq                0         0
largepages                     0         0
mmio_exits               1559403      1028
mmu_cache_miss            632126        20
mmu_flooded               390870        18
mmu_pde_zapped            583597         0
mmu_pte_updated          2865958       115
mmu_pte_write            3305636       124
mmu_recycled               11499         0
mmu_shadow_zapped         869397        19
mmu_unsync                 14604         2
mmu_unsync_global             52         3
nmi_injections                 0         0
nmi_window                     0         0
pf_fixed                50061696      8219
pf_guest                19885071        44
remote_tlb_flush          396841       482
request_nmi                    0         0
signal_exits                  17         0
tlb_flush               25014198      5954


64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=653 ttl=64
time=0.544 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=654 ttl=64
time=0.528 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=655 ttl=64
time=0.559 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=656 ttl=64
time=0.510 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=657 ttl=64
time=646 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=658 ttl=64
time=280 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=659 ttl=64
time=314 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=660 ttl=64
time=426 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=661 ttl=64
time=279 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=662 ttl=64
time=909 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=663 ttl=64
time=50.1 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=664 ttl=64
time=1314 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=665 ttl=64
time=306 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=666 ttl=64
time=0.520 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=667 ttl=64
time=0.540 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=668 ttl=64
time=0.527 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=669 ttl=64
time=0.463 ms

Fri Jan  9 22:55:05 CST 2009
efer_reload                   36         0
exits                  259877054     21262
fpu_reload              10735085       904
halt_exits              15068364      2937
halt_wakeup              3140715       755
host_state_reload       61698616      9249
hypercalls                 90713        20
insn_emulation          21669992      3342
insn_emulation_fail          439         0
invlpg                  10299732       189
io_exits               102981490     10766
irq_exits                1121997       261
irq_injections          18987120      4384
irq_window               3131184      1378
kvm_request_irq                0         0
largepages                     0         0
mmio_exits               1589318        70
mmu_cache_miss            641035         6
mmu_flooded               397311         6
mmu_pde_zapped            589210         0
mmu_pte_updated          2878333        19
mmu_pte_write            3322010        22
mmu_recycled               11541         0
mmu_shadow_zapped         881104        12
mmu_unsync                 14980       -26
mmu_unsync_global             80       -26
nmi_injections                 0         0
nmi_window                     0         0
pf_fixed                50348837      1654
pf_guest                19974876         9
remote_tlb_flush          406310         1
request_nmi                    0         0
signal_exits                  17         0
tlb_flush               25414312       705

Fri Jan  9 22:55:07 CST 2009
efer_reload                   36         0
exits                  259923167     22544
fpu_reload              10737416       999
halt_exits              15075348      2923
halt_wakeup              3142504       732
host_state_reload       61719360      9164
hypercalls                 90765        22
insn_emulation          21676868      3324
insn_emulation_fail          439         0
invlpg                  10299986       219
io_exits               103005825     10631
irq_exits                1122654       287
irq_injections          18996545      4286
irq_window               3133448      1258
kvm_request_irq                0         0
largepages                     0         0
mmio_exits               1589442       116
mmu_cache_miss            641047        12
mmu_flooded               397323        12
mmu_pde_zapped            589210         0
mmu_pte_updated          2878384        35
mmu_pte_write            3322067        41
mmu_recycled               11541         0
mmu_shadow_zapped         881116        12
mmu_unsync                 14993         3
mmu_unsync_global             95         4
nmi_injections                 0         0
nmi_window                     0         0
pf_fixed                50352007      3057
pf_guest                19974896        18
remote_tlb_flush          406317         4
request_nmi                    0         0
signal_exits                  17         0
tlb_flush               25415857       904


64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=721 ttl=64
time=0.527 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=722 ttl=64
time=0.551 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=723 ttl=64
time=0.466 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=724 ttl=64
time=0.509 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=725 ttl=64
time=693 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=726 ttl=64
time=3397 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=727 ttl=64
time=2397 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=728 ttl=64
time=1397 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=729 ttl=64
time=398 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=730 ttl=64
time=941 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=731 ttl=64
time=1482 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=732 ttl=64
time=479 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=733 ttl=64
time=0.527 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=734 ttl=64
time=0.505 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=735 ttl=64
time=0.507 ms
64 bytes from hermes.wumi.org.au (192.168.0.249): icmp_seq=736 ttl=64
time=0.517 ms

Fri Jan  9 22:56:10 CST 2009
efer_reload                   36         0
exits                  261534571     17234
fpu_reload              10800236      1321
halt_exits              15286560      2917
halt_wakeup              3187952       733
host_state_reload       62313130      8560
hypercalls                 92031        21
insn_emulation          21876899      2682
insn_emulation_fail          439         0
invlpg                  10315553        37
io_exits               103688141      9916
irq_exits                1128041       310
irq_injections          19255926      3755
irq_window               3177005       788
kvm_request_irq                0         0
largepages                     0         0
mmio_exits               1598313        18
mmu_cache_miss            643199         0
mmu_flooded               398982         0
mmu_pde_zapped            590559         0
mmu_pte_updated          2881041         1
mmu_pte_write            3325787         1
mmu_recycled               11541         0
mmu_shadow_zapped         884135         0
mmu_unsync                 15024        -9
mmu_unsync_global             57       -10
nmi_injections                 0         0
nmi_window                     0         0
pf_fixed                50419230        84
pf_guest                19997609         2
remote_tlb_flush          408036         1
request_nmi                    0         0
signal_exits                  17         0
tlb_flush               25507415       454

Fri Jan  9 22:56:13 CST 2009
efer_reload                   36         0
exits                  261583705     21909
fpu_reload              10804448      1674
halt_exits              15293967      2915
halt_wakeup              3189804       720
host_state_reload       62336274      9638
hypercalls                 92079        18
insn_emulation          21884951      3758
insn_emulation_fail          439         0
invlpg                  10316276       705
io_exits               103714609     10873
irq_exits                1128838       299
irq_injections          19266675      4707
irq_window               3180199      1728
kvm_request_irq                0         0
largepages                     0         0
mmio_exits               1598498       180
mmu_cache_miss            643200         0
mmu_flooded               398982         0
mmu_pde_zapped            590559         0
mmu_pte_updated          2881048         7
mmu_pte_write            3325794         7
mmu_recycled               11541         0
mmu_shadow_zapped         884144         9
mmu_unsync                 15006       -36
mmu_unsync_global             40       -34
nmi_injections                 0         0
nmi_window                     0         0
pf_fixed                50420142       802
pf_guest                19997630         0
remote_tlb_flush          408042         1
request_nmi                    0         0
signal_exits                  17         0
tlb_flush               25509336      1365


----------------------------------------------------------------------

Comment By: Amit Shah (amitshah)
Date: 2009-01-09 22:17

Message:
If you experience a stall, can you see what the kvm_stat output is at that
time and attach that?

(kvm_stat is included in the kvm tarball)

----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2009-01-09 22:12

Message:
I've done some more testing tonight and unfortunately it's not quite as
easy to reproduce as I had hoped. Here's what I got so far:

Test1 - Linux 2.6.27.10, kvm-82

$ ping -c 600 hermes-old

(with no other guests running)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599283ms
rtt min/avg/max/mdev = 0.211/0.407/7.145/0.345 ms

(three other guests)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599423ms
rtt min/avg/max/mdev = 0.194/0.497/6.364/0.290 ms

(all guests running)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599506ms
rtt min/avg/max/mdev = 0.254/0.577/22.347/0.932 ms

Test2 - Linux 2.6.28, kvm-82

(with no other guests running)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599367ms
rtt min/avg/max/mdev = 0.206/0.408/6.768/0.279 ms

(three other guests)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599347ms
rtt min/avg/max/mdev = 0.254/0.582/77.566/3.166 ms

(all guests running)
--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599681ms
rtt min/avg/max/mdev = 0.256/328.184/10335.007/1024.143 ms, pipe 11

So, the problem did surface again but only the one time. It could be a
2.6.28 specific thing, a bad interaction between the running guests,
something that triggers after a certain amount of guest/host uptime... who
knows. I need to find a more reliable way to trigger it before I will be
able to bisect. Any suggestions welcome.


----------------------------------------------------------------------

Comment By: Kevin Shanahan (kmshanah)
Date: 2009-01-09 11:17

Message:
I forgot to give the command line for the Linux guest:

/usr/local/kvm/bin/qemu-system-x86_64 \
    -smp 2 \
    -localtime -m 2048 \
    -hda kvm-17-1.img \
    -hdb kvm-17-tmp.img \
    -net nic,vlan=0,macaddr=52:54:00:12:34:67,model=rtl8139 \
    -net tap,vlan=0,ifname=tap17,script=no \
    -vnc 127.0.0.1:17 -usbdevice tablet \
    -daemonize


----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=893831&aid=2494730&group_id=180599
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html


[Index of Archives]     [KVM ARM]     [KVM ia64]     [KVM ppc]     [Virtualization Tools]     [Spice Development]     [Libvirt]     [Libvirt Users]     [Linux USB Devel]     [Linux Audio Users]     [Yosemite Questions]     [Linux Kernel]     [Linux SCSI]     [XFree86]
  Powered by Linux