Re: Hangs

Roland Lammel
2008-11-19T21:56:21Z

Actually it just happenend again with the host running kvm-79. Host
CPU is at 100% but I'm still able to login (it recovered from the
first hang). But I'm not able to start e.g. top.
Writing to disk works (e.g. dd /dev/zero to /tmp/test.file with 1MB,
1G already caused the instance to hang)

In the guest I see:

The soft lockup of CPU#0 (only 1 cpu assigned to the guest) seems to
be either caused by or cause itself the clock problem

bit:~# date
Fri Dec 6 13:50:40 CET 1912

[ 57.348217] eth1: no IPv6 routers present
[1266956800.037898] BUG: soft lockup - CPU#0 stuck for 1179869795s!
[logcheck:23795]
[1266956800.037898] Modules linked in: ipv6 dm_snapshot dm_mirror
dm_log dm_mod loop virtio_balloon serio_raw snd_pcsp virtio_net
snd_pcm snd_timer snd soundcore psmouse snd_page_alloc evdev ext3 jbd
mbcache ide_cd_mod cdrom ata_generic libata scsi_mod dock
ide_pci_generic virtio_blk uhci_hcd usbcore piix ide_core virtio_pci
thermal_sys
[1266956800.037898]
[1266956800.037898] Pid: 23795, comm: logcheck Not tainted (2.6.26-1-486 #1)
[1266956800.037898] EIP: 0060:[<c0118c28>] EFLAGS: 00000246 CPU: 0
[1266956800.037898] EIP is at finish_task_switch+0x20/0x78
[1266956800.037898] EAX: c03cb620 EBX: de82e800 ECX: 00000003 EDX: de824000
[1266956800.037898] ESI: 00000000 EDI: de824000 EBP: 00000000 ESP: c51e1f9c
[1266956800.037898] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068
[1266956800.037898] CR0: 8005003b CR2: 088a711c CR3: 04f08000 CR4: 00000690
[1266956800.037898] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[1266956800.037898] DR6: ffff0ff0 DR7: 00000400
[1266956800.037898] [<c0118e22>] schedule_tail+0xe/0x39
[1266956800.037898] [<c0103646>] ret_from_fork+0x6/0x20
[1266956800.037898] =======================
[1266957741.780134] INFO: task postdrop:24584 blocked for more than 120 seconds.
[1266957741.780592] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[1266957741.781276] postdrop D c014f55e 0 24584 24583
[1266957741.781696] de894000 00000086 00000000 c014f55e
49506ad8 1195233c de89418c 00013315
[1266957741.782256] 00000000 bf229803 bf229803 d41593ec
ddb2d400 c02a5b89 c03ec750 ddbf319c
[1266957741.783040] bf229803 c0121fc7 de894000 c03ec700
c02a5b84 74736f70 706f7264 642d7000

On the host I see (with 2 other guests running with no load):
KVM stat on the hosts shows:
kvm statistics

efer_reload 0 0
exits 83407498 2353
fpu_reload 399797 17
halt_exits 2079501 18
halt_wakeup 67976 0
host_state_reload 5925084 38
hypercalls 20515664 0
insn_emulation 22039607 1318
insn_emulation_fail 0 0
invlpg 3237765 0
io_exits 3745042 0
irq_exits 1845939 722
irq_injections 3705460 704
irq_window 0 0
kvm_request_irq 0 0
largepages 0 0
mmio_exits 82282 0
mmu_cache_miss 1533699 0
mmu_flooded 1194315 0
mmu_pde_zapped 1468996 0
mmu_pte_updated 18613367 0
mmu_pte_write 28421353 0
mmu_recycled 0 0
mmu_shadow_zapped 1779168 0
mmu_unsync 18 0
nmi_injections 0 0
nmi_window 0 0
pf_fixed 15449889 0
pf_guest 18947094 0
remote_tlb_flush 2 0
request_nmi 0 0
signal_exits 0 0
tlb_flush 25533150 255

Clock sources used are (for host and guest):
host:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource
acpi_pm
host:~# cat /sys/devices/system/clocksource/clocksource0/available_clocksource
acpi_pm jiffies tsc

guest:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource
kvm-clock
guest:~# cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock jiffies tsc
bit:~#

Commandline for starting is (kvm-79):
/usr/local/bin/qemu-system-x86_64 -S -M pc -m 500 -smp 1 -name bit
-monitor pty -no-acpi -boot c -drive
file=/var/kvm/bit.img,if=virtio,index=0,boot=on -net
nic,macaddr=24:42:53:21:52:45,vlan=0,model=virtio -net
tap,fd=11,script=,vlan=0,ifname=vnet0 -serial tcp:127.0.0.1:50401
-parallel none -usb -vnc 0.0.0.0:45001

Hope that helps, Cheers

+rl
--
Roland Lammel
QuikIT - IT Lösungen - flexibel und schnell
Web: http://www.quikit.at
Email: info@quikit.at

"Enjoy your job, make lots of money, work within the law. Choose any two."