#322 kvm locks up system
Sometimes KVM locks up the entire system for several minutes. When this happens I can't use neither the keyboard nor the mouse.
I can login remotely using ssh and kill kvm, and then keyboard is restored after a short while, however I need to restart X, because the mouse remains grabbed.
Last time it happened while using a NetBSD 4.0 (x86_64) image.
I've done a commit all on the qemu console, then switched back to the guest, and I couldn't type anything, after that I couldn't exit the grab either, and after that the system locked up.
I had gkrellm running, and it showed 1 core having 100% system time, while the other 3 cores were idle. Before this happened were at 99% user CPU usage, from another process (not kvm/qemu).
System info:
distro: Debian unstable
CPU: Intel(R) Core(TM)2 Quad CPU Q9550 @ 2.83GHz
KVM version: 76
host kernel: 2.6.26-1-amd64 #1 SMP Wed Sep 24 13:59:41 UTC 2008 x86_64 GNU/Linux
host arch: x86_64
guest: x86_64, NetBSD 4.0 (on serial console, boot fails if using text console)
qemu cmdline:
sudo qemu-system-x86_64 -hda netbsd4.img -snapshot -m 1024 -cdrom /tmp/x.iso the problem only appears with kvm, I never encountered this when using -no-kvm, or when using qemu w/ kqemu.
* this problem also occured when running a Solaris 10 guest OS
dmesg output during lockup below.
See also kerneloops entry:
http://kerneloops.org/guilty.php?guilty=apic_mmio_read&version=2.6.26-release&start=1736704&end=1769471&class=oops
[12518.803078] loaded kvm module (kvm-76)
[12564.289154] kvm: emulating exchange as write
[13926.593155] kvm: inject_page_fault: double fault 0xffffffff80c0bfa8
[14015.554904] BUG: soft lockup - CPU#1 stuck for 61s! [qemu-system-x86:20613]
[14015.554904] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14015.554904] CPU 1:
[14015.554904] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14015.554904] Pid: 20613, comm: qemu-system-x86 Tainted: P 2.6.26-1-amd64 #1
[14015.554904] RIP: 0010:[<ffffffffa0c0fa32>] [<ffffffffa0c0fa32>] :kvm:apic_mmio_read+0xf0/0x17d
[14015.554904] RSP: 0018:ffff81000821dc88 EFLAGS: 00000202
[14015.554904] RAX: 62126c0cf17912e9 RBX: 0000000000000390 RCX: 62126c0cf2841a1b
[14015.554904] RDX: 00000000010b0732 RSI: 00000000010b0732 RDI: fffffffffef4f8ce
[14015.554904] RBP: 00000000fee0017b R08: 0000000000000001 R09: 0000000000000c12
[14015.554904] R10: 0000000000000000 R11: ffffffffa0c60c5b R12: 0000000380281e01
[14015.554904] R13: 0000000000c18dc0 R14: 0000000300000000 R15: ffffffff809b8390
[14015.554904] FS: 00000000420ce950(0000) GS:ffff81012fa7c8c0(0000) knlGS:0000000000000000
[14015.554904] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[14015.554904] CR2: 0000000000000000 CR3: 0000000091b53000 CR4: 00000000000026e0
[14015.554904] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[14015.554904] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[14015.554904]
[14015.554904] Call Trace:
[14015.554904] [<ffffffffa0c0f9d1>] ? :kvm:apic_mmio_read+0x8f/0x17d
[14015.554904] [<ffffffffa0bffeb9>] ? :kvm:vcpu_find_mmio_dev+0x29/0x59
[14015.554904] [<ffffffffa0c001cd>] ? :kvm:emulator_read_emulated+0xa5/0xeb
[14015.554904] [<ffffffffa0c096f5>] ? :kvm:x86_emulate_insn+0x10b/0x473a
[14015.554904] [<ffffffffa0c09407>] ? :kvm:do_insn_fetch+0x67/0xa6
[14015.554904] [<ffffffffa0c0e6ca>] ? :kvm:x86_decode_insn+0x9a6/0xa84
[14015.554904] [<ffffffffa0c071eb>] ? :kvm:mmu_sync_fn+0x0/0x2b
[14015.554904] [<ffffffffa0c003ac>] ? :kvm:emulate_instruction+0x199/0x25d
[14015.554904] [<ffffffff804297c1>] ? down_read+0x12/0xa1
[14015.554904] [<ffffffffa0c60c74>] ? :kvm_intel:handle_apic_access+0x19/0x42
[14015.554904] [<ffffffffa0c02daf>] ? :kvm:kvm_arch_vcpu_ioctl_run+0x43c/0x64f
[14015.554904] [<ffffffffa0bfeb81>] ? :kvm:kvm_vcpu_ioctl+0xf2/0x448
[14015.554904] [<ffffffffa0bfe8e9>] ? :kvm:kvm_vm_ioctl+0x208/0x221
[14015.554904] [<ffffffff802a6435>] ? vfs_ioctl+0x21/0x6b
[14015.554904] [<ffffffff802a66c7>] ? do_vfs_ioctl+0x248/0x261
[14015.554904] [<ffffffff802a6731>] ? sys_ioctl+0x51/0x70
[14015.554904] [<ffffffff8020bf49>] ? sysret_signal+0x2b/0x45
[14015.554904] [<ffffffff8020be9a>] ? system_call_after_swapgs+0x8a/0x8f
[14015.554904]
[14081.050390] BUG: soft lockup - CPU#1 stuck for 61s! [qemu-system-x86:20613]
[14081.050390] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14081.050390] CPU 1:
[14081.050390] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14081.050390] Pid: 20613, comm: qemu-system-x86 Tainted: P 2.6.26-1-amd64 #1
[14081.050390] RIP: 0010:[<ffffffffa0c0fa3c>] [<ffffffffa0c0fa3c>] :kvm:apic_mmio_read+0xfa/0x17d
[14081.050390] RSP: 0018:ffff81000821dc88 EFLAGS: 00000212
[14081.050390] RAX: 434cfcfecd26aebf RBX: 0000000000000390 RCX: 434cfcfece31b5f1
[14081.050390] RDX: 00000000010b0732 RSI: 00000000010b0732 RDI: fffffffffef4f8ce
[14081.050390] RBP: 00000000fee0017b R08: 0000000000000001 R09: 0000000000000c12
[14081.050390] R10: 0000000000000000 R11: ffffffffa0c60c5b R12: 0000000380281e01
[14081.050390] R13: 0000000000c18dc0 R14: 0000000300000000 R15: ffffffff809b8390
[14081.050390] FS: 00000000420ce950(0000) GS:ffff81012fa7c8c0(0000) knlGS:0000000000000000
[14081.050390] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[14081.050390] CR2: 0000000000000000 CR3: 0000000091b53000 CR4: 00000000000026e0
[14081.050390] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[14081.050390] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[14081.050390]
[14081.050390] Call Trace:
[14081.050390] [<ffffffffa0c0f9d1>] ? :kvm:apic_mmio_read+0x8f/0x17d
[14081.050390] [<ffffffffa0bffeb9>] ? :kvm:vcpu_find_mmio_dev+0x29/0x59
[14081.050390] [<ffffffffa0c001cd>] ? :kvm:emulator_read_emulated+0xa5/0xeb
[14081.050390] [<ffffffffa0c096f5>] ? :kvm:x86_emulate_insn+0x10b/0x473a
[14081.050390] [<ffffffffa0c09407>] ? :kvm:do_insn_fetch+0x67/0xa6
[14081.050390] [<ffffffffa0c0e6ca>] ? :kvm:x86_decode_insn+0x9a6/0xa84
[14081.050390] [<ffffffffa0c071eb>] ? :kvm:mmu_sync_fn+0x0/0x2b
[14081.050390] [<ffffffffa0c003ac>] ? :kvm:emulate_instruction+0x199/0x25d
[14081.050390] [<ffffffff804297c1>] ? down_read+0x12/0xa1
[14081.050390] [<ffffffffa0c60c74>] ? :kvm_intel:handle_apic_access+0x19/0x42
[14081.050390] [<ffffffffa0c02daf>] ? :kvm:kvm_arch_vcpu_ioctl_run+0x43c/0x64f
[14081.050390] [<ffffffffa0bfeb81>] ? :kvm:kvm_vcpu_ioctl+0xf2/0x448
[14081.050390] [<ffffffffa0bfe8e9>] ? :kvm:kvm_vm_ioctl+0x208/0x221
[14081.050390] [<ffffffff802a6435>] ? vfs_ioctl+0x21/0x6b
[14081.050390] [<ffffffff802a66c7>] ? do_vfs_ioctl+0x248/0x261
[14081.050390] [<ffffffff802a6731>] ? sys_ioctl+0x51/0x70
[14081.050390] [<ffffffff8020bf49>] ? sysret_signal+0x2b/0x45
[14081.050390] [<ffffffff8020be9a>] ? system_call_after_swapgs+0x8a/0x8f
[14081.050390]
[14083.200368] INFO: task clamd:8043 blocked for more than 120 seconds.
[14083.200372] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[14083.200375] clamd D 0000000000001000 0 8043 1
[14083.200380] ffff810125defad8 0000000000000086 ffff81007d9f1a00 0000000000000000
[14083.200386] 0000000000000000 ffff81012f05aad0 ffff8100781e5160 ffff81012f05ad58
[14083.200392] 0000000000000001 ffff81007d9f1a00 ffff8100c435bf00 0000000000000296
[14083.200397] Call Trace:
[14083.200420] [<ffffffff80428753>] schedule_timeout+0x1e/0xad
[14083.200429] [<ffffffff80428eb9>] down+0x64/0x91
[14083.200436] [<ffffffff802495d6>] down+0x27/0x36
[14083.200464] [<ffffffffa035ede2>] :xfs:_xfs_buf_find+0x151/0x1da
[14083.200490] [<ffffffffa035eebd>] :xfs:xfs_buf_get_flags+0x52/0x13c
[14083.200517] [<ffffffffa035f6bb>] :xfs:xfs_buf_read_flags+0x12/0x7f
[14083.200544] [<ffffffffa0354abf>] :xfs:xfs_trans_read_buf+0x47/0x2af
[14083.200572] [<ffffffffa03301fa>] :xfs:xfs_da_do_buf+0x40f/0x636
[14083.200598] [<ffffffffa035e7ac>] :xfs:_xfs_buf_lookup_pages+0x298/0x2ca
[14083.200633] [<ffffffffa033048b>] :xfs:xfs_da_read_buf+0x24/0x29
[14083.200659] [<ffffffffa0335633>] :xfs:xfs_dir2_leaf_getdents+0x381/0x61a
[14083.200685] [<ffffffffa0335633>] :xfs:xfs_dir2_leaf_getdents+0x381/0x61a
[14083.200712] [<ffffffffa035ff01>] :xfs:xfs_hack_filldir+0x0/0x5b
[14083.200741] [<ffffffffa035ff01>] :xfs:xfs_hack_filldir+0x0/0x5b
[14083.200768] [<ffffffffa03325c4>] :xfs:xfs_readdir+0xa6/0xb5
[14083.200796] [<ffffffffa035febb>] :xfs:xfs_file_readdir+0xff/0x145
[14083.200801] [<ffffffff802a6808>] filldir+0x0/0xb7
[14083.200809] [<ffffffff802a6808>] filldir+0x0/0xb7
[14083.200812] [<ffffffff802a6934>] vfs_readdir+0x75/0xa7
[14083.200818] [<ffffffff802a6b84>] sys_getdents+0x75/0xbd
[14083.200826] [<ffffffff8020be9a>] system_call_after_swapgs+0x8a/0x8f
[14083.200834]
[14146.548708] BUG: soft lockup - CPU#1 stuck for 61s! [qemu-system-x86:20613]
[14146.548708] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14146.548708] CPU 1:
[14146.548708] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14146.548708] Pid: 20613, comm: qemu-system-x86 Tainted: P 2.6.26-1-amd64 #1
[14146.548708] RIP: 0010:[<ffffffffa0c0fa32>] [<ffffffffa0c0fa32>] :kvm:apic_mmio_read+0xf0/0x17d
[14146.548708] RSP: 0018:ffff81000821dc88 EFLAGS: 00000216
[14146.548708] RAX: 248f234114b550af RBX: 0000000000000390 RCX: 248f234115c057e1
[14146.548708] RDX: 00000000010b0732 RSI: 00000000010b0732 RDI: fffffffffef4f8ce
[14146.548708] RBP: 00000000fee0017b R08: 0000000000000001 R09: 0000000000000c12
[14146.548708] R10: 0000000000000000 R11: ffffffffa0c60c5b R12: 0000000380281e01
[14146.548708] R13: 0000000000c18dc0 R14: 0000000300000000 R15: ffffffff809b8390
[14146.548708] FS: 00000000420ce950(0000) GS:ffff81012fa7c8c0(0000) knlGS:0000000000000000
[14146.548708] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[14146.548708] CR2: 0000000000000000 CR3: 0000000091b53000 CR4: 00000000000026e0
[14146.548708] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[14146.548708] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[14146.548708]
[14146.548708] Call Trace:
[14146.548708] [<ffffffffa0c0f9d1>] ? :kvm:apic_mmio_read+0x8f/0x17d
[14146.548708] [<ffffffffa0bffeb9>] ? :kvm:vcpu_find_mmio_dev+0x29/0x59
[14146.548708] [<ffffffffa0c001cd>] ? :kvm:emulator_read_emulated+0xa5/0xeb
[14146.548708] [<ffffffffa0c096f5>] ? :kvm:x86_emulate_insn+0x10b/0x473a
[14146.548708] [<ffffffffa0c09407>] ? :kvm:do_insn_fetch+0x67/0xa6
[14146.548708] [<ffffffffa0c0e6ca>] ? :kvm:x86_decode_insn+0x9a6/0xa84
[14146.548708] [<ffffffffa0c071eb>] ? :kvm:mmu_sync_fn+0x0/0x2b
[14146.548708] [<ffffffffa0c003ac>] ? :kvm:emulate_instruction+0x199/0x25d
[14146.548708] [<ffffffff804297c1>] ? down_read+0x12/0xa1
[14146.548708] [<ffffffffa0c60c74>] ? :kvm_intel:handle_apic_access+0x19/0x42
[14146.548708] [<ffffffffa0c02daf>] ? :kvm:kvm_arch_vcpu_ioctl_run+0x43c/0x64f
[14146.548708] [<ffffffffa0bfeb81>] ? :kvm:kvm_vcpu_ioctl+0xf2/0x448
[14146.548708] [<ffffffffa0bfe8e9>] ? :kvm:kvm_vm_ioctl+0x208/0x221
[14146.548708] [<ffffffff802a6435>] ? vfs_ioctl+0x21/0x6b
[14146.548708] [<ffffffff802a66c7>] ? do_vfs_ioctl+0x248/0x261
[14146.548708] [<ffffffff802a6731>] ? sys_ioctl+0x51/0x70
[14146.548708] [<ffffffff8020bf49>] ? sysret_signal+0x2b/0x45
[14146.548708] [<ffffffff8020be9a>] ? system_call_after_swapgs+0x8a/0x8f
[14146.548708]
[14212.047262] BUG: soft lockup - CPU#1 stuck for 61s! [qemu-system-x86:20613]
[14212.047262] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14212.047262] CPU 1:
[14212.047262] Modules linked in: kvm_intel kvm tun kqemu ppdev parport_pc lp parport nvidia(P) ipv6 video output ac battery xt_tcpudp nf_conntrack_ipv4 xt_state nf_conntrack iptable_filter ip_tables x_tables cpufreq_conservative cpufreq_powersave cpufreq_stats cpufreq_userspace cpufreq_ondemand xfs reiserfs acpi_cpufreq freq_table coretemp it87 hwmon_vid sbp2 loop ide_cd_mod cdrom ide_pci_generic jmicron snd_pcm_oss snd_mixer_oss ide_core snd_hda_intel ohci1394 i2c_i801 serio_raw snd_seq_dummy i2c_core snd_seq_oss floppy ieee1394 ata_generic pcspkr snd_pcm psmouse snd_seq_midi_event r8169 sata_sil24 snd_seq snd_timer snd_seq_device ehci_hcd button uhci_hcd snd soundcore snd_page_alloc intel_agp evdev ext3 jbd mbcache dm_mirror dm_log dm_snapshot dm_mod raid10 raid1 md_mod sd_mod thermal processor fan thermal_sys ahci libata scsi_mod dock [last unloaded: kvm]
[14212.047262] Pid: 20613, comm: qemu-system-x86 Tainted: P 2.6.26-1-amd64 #1
[14212.047262] RIP: 0010:[<ffffffffa0c0fa32>] [<ffffffffa0c0fa32>] :kvm:apic_mmio_read+0xf0/0x17d
[14212.047262] RSP: 0018:ffff81000821dc88 EFLAGS: 00000202
[14212.047262] RAX: 05d79760b9d55861 RBX: 0000000000000390 RCX: 05d79760bae05f93
[14212.047262] RDX: 00000000010b0732 RSI: 00000000010b0732 RDI: fffffffffef4f8ce
[14212.047262] RBP: 00000000fee0017b R08: 0000000000000001 R09: 0000000000000c12
[14212.047262] R10: 0000000000000000 R11: ffffffffa0c60c5b R12: 0000000380281e01
[14212.047262] R13: 0000000000c18dc0 R14: 0000000300000000 R15: ffffffff809b8390
[14212.047262] FS: 00000000420ce950(0000) GS:ffff81012fa7c8c0(0000) knlGS:0000000000000000
[14212.047262] CS: 0010 DS: 002b ES: 002b CR0: 000000008005003b
[14212.047262] CR2: 0000000000000000 CR3: 0000000091b53000 CR4: 00000000000026e0
[14212.047262] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[14212.047262] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[14212.047262]
[14212.047262] Call Trace:
[14212.047262] [<ffffffffa0c0f9d1>] ? :kvm:apic_mmio_read+0x8f/0x17d
[14212.047262] [<ffffffffa0bffeb9>] ? :kvm:vcpu_find_mmio_dev+0x29/0x59
[14212.047262] [<ffffffffa0c001cd>] ? :kvm:emulator_read_emulated+0xa5/0xeb
[14212.047262] [<ffffffffa0c096f5>] ? :kvm:x86_emulate_insn+0x10b/0x473a
[14212.047262] [<ffffffffa0c09407>] ? :kvm:do_insn_fetch+0x67/0xa6
[14212.047262] [<ffffffffa0c0e6ca>] ? :kvm:x86_decode_insn+0x9a6/0xa84
[14212.047262] [<ffffffffa0c071eb>] ? :kvm:mmu_sync_fn+0x0/0x2b
[14212.047262] [<ffffffffa0c003ac>] ? :kvm:emulate_instruction+0x199/0x25d
[14212.047262] [<ffffffff804297c1>] ? down_read+0x12/0xa1
[14212.047262] [<ffffffffa0c60c74>] ? :kvm_intel:handle_apic_access+0x19/0x42
[14212.047262] [<ffffffffa0c02daf>] ? :kvm:kvm_arch_vcpu_ioctl_run+0x43c/0x64f
[14212.047262] [<ffffffffa0bfeb81>] ? :kvm:kvm_vcpu_ioctl+0xf2/0x448
[14212.047262] [<ffffffffa0bfe8e9>] ? :kvm:kvm_vm_ioctl+0x208/0x221
[14212.047262] [<ffffffff802a6435>] ? vfs_ioctl+0x21/0x6b
[14212.047262] [<ffffffff802a66c7>] ? do_vfs_ioctl+0x248/0x261
[14212.047262] [<ffffffff802a6731>] ? sys_ioctl+0x51/0x70
[14212.047262] [<ffffffff8020bf49>] ? sysret_signal+0x2b/0x45
[14212.047262] [<ffffffff8020be9a>] ? system_call_after_swapgs+0x8a/0x8f
[14212.047262]
[14212.050788] INFO: task clamd:8043 blocked for more than 120 seconds.
[14212.050792] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[14212.050794] clamd D 0000000000001000 0 8043 1
[14212.050799] ffff810125defad8 0000000000000086 ffff81007d9f1a00 0000000000000000
[14212.050805] 0000000000000000 ffff81012f05aad0 ffff8100781e5160 ffff81012f05ad58
[14212.050811] 0000000000000001 ffff81007d9f1a00 ffff8100c435bf00 0000000000000296
[14212.050816] Call Trace:
[14212.050840] [<ffffffff80428753>] schedule_timeout+0x1e/0xad
[14212.050849] [<ffffffff80428eb9>] down+0x64/0x91
[14212.050855] [<ffffffff802495d6>] down+0x27/0x36
[14212.050883] [<ffffffffa035ede2>] :xfs:_xfs_buf_find+0x151/0x1da
[14212.050911] [<ffffffffa035eebd>] :xfs:xfs_buf_get_flags+0x52/0x13c
[14212.050938] [<ffffffffa035f6bb>] :xfs:xfs_buf_read_flags+0x12/0x7f
[14212.050965] [<ffffffffa0354abf>] :xfs:xfs_trans_read_buf+0x47/0x2af
[14212.050991] [<ffffffffa03301fa>] :xfs:xfs_da_do_buf+0x40f/0x636
[14212.051017] [<ffffffffa035e7ac>] :xfs:_xfs_buf_lookup_pages+0x298/0x2ca
[14212.051052] [<ffffffffa033048b>] :xfs:xfs_da_read_buf+0x24/0x29
[14212.051079] [<ffffffffa0335633>] :xfs:xfs_dir2_leaf_getdents+0x381/0x61a
[14212.051104] [<ffffffffa0335633>] :xfs:xfs_dir2_leaf_getdents+0x381/0x61a
[14212.051130] [<ffffffffa035ff01>] :xfs:xfs_hack_filldir+0x0/0x5b
[14212.051160] [<ffffffffa035ff01>] :xfs:xfs_hack_filldir+0x0/0x5b
[14212.051186] [<ffffffffa03325c4>] :xfs:xfs_readdir+0xa6/0xb5
[14212.051213] [<ffffffffa035febb>] :xfs:xfs_file_readdir+0xff/0x145
[14212.051217] [<ffffffff802a6808>] filldir+0x0/0xb7
[14212.051225] [<ffffffff802a6808>] filldir+0x0/0xb7
[14212.051229] [<ffffffff802a6934>] vfs_readdir+0x75/0xa7
[14212.051235] [<ffffffff802a6b84>] sys_getdents+0x75/0xbd
[14212.051243] [<ffffffff8020be9a>] system_call_after_swapgs+0x8a/0x8f
[14212.051252]
This just happened again, just after issuing a 'commit all' command in qemu while running NetBSD4.0, this time the keyboard&mouse wasn't captured, but the keyboard was unusable (it kept repeating 11111....). [I issued commit all command, got the qemu prompt back, then switched to the serial console, then I noticed 100% sys CPU usage, and the lockup in dmesg]
I tried kill -9 as root on the kvm process, and it had no effect.
I had no luck creating an hypothesis for this.
Did it used to work reliably in the past? If so, can you bisect to find the culprit commit?
Can you disassemble kvm.ko so we can see where the problem is (objdump -Dr kvm.ko; make sure it is exactly the binary that was running)
Here is the dissasembly, return address is at 129d1, so it is that callq *0x28(%rax).
I can't bisect this, since I don't know if there is a working version (only recently bought a hardware virt capable CPU).
0000000000012942 <apic_mmio_read>:
12942: 41 56 push %r14
12944: 49 89 ce mov %rcx,%r14
12947: 41 55 push %r13
12949: 41 54 push %r12
1294b: 41 89 d4 mov %edx,%r12d
1294e: 89 f2 mov %esi,%edx
12950: 55 push %rbp
12951: 53 push %rbx
12952: 48 83 ec 10 sub $0x10,%rsp
12956: 48 8b 5f 20 mov 0x20(%rdi),%rbx
1295a: 2b 13 sub (%rbx),%edx
1295c: 88 d0 mov %dl,%al
1295e: 83 e0 0f and $0xf,%eax
12961: 41 88 c5 mov %al,%r13b
12964: 0f b6 c0 movzbl %al,%eax
12967: 44 01 e0 add %r12d,%eax
1296a: 83 f8 04 cmp $0x4,%eax
1296d: 7e 16 jle 12985 <apic_mmio_read+0x43>
1296f: 44 89 e2 mov %r12d,%edx
12972: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
12975: R_X86_64_32S .rodata.str1.1+0xbf6
12979: 31 c0 xor %eax,%eax
1297b: e8 00 00 00 00 callq 12980 <apic_mmio_read+0x3e>
1297c: R_X86_64_PC32 printk+0xfffffffffffffffc
12980: e9 2d 01 00 00 jmpq 12ab2 <apic_mmio_read+0x170>
12985: 89 d5 mov %edx,%ebp
12987: 83 e5 f0 and $0xfffffffffffffff0,%ebp
1298a: 81 fd ff 0f 00 00 cmp $0xfff,%ebp
12990: 0f 87 df 00 00 00 ja 12a75 <apic_mmio_read+0x133>
12996: 81 fd 90 00 00 00 cmp $0x90,%ebp
1299c: 74 19 je 129b7 <apic_mmio_read+0x75>
1299e: 81 fd 90 03 00 00 cmp $0x390,%ebp
129a4: 74 24 je 129ca <apic_mmio_read+0x88>
129a6: 81 fd 80 00 00 00 cmp $0x80,%ebp
129ac: 0f 85 ac 00 00 00 jne 12a5e <apic_mmio_read+0x11c>
129b2: e9 8d 00 00 00 jmpq 12a44 <apic_mmio_read+0x102>
129b7: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
129ba: R_X86_64_32S .rodata.str1.1+0xc1f
129be: 31 c0 xor %eax,%eax
129c0: e8 00 00 00 00 callq 129c5 <apic_mmio_read+0x83>
129c1: R_X86_64_PC32 printk+0xfffffffffffffffc
129c5: e9 ab 00 00 00 jmpq 12a75 <apic_mmio_read+0x133>
129ca: 48 8b 43 78 mov 0x78(%rbx),%rax
129ce: ff 50 28 callq *0x28(%rax)
129d1: 48 8b bb d0 00 00 00 mov 0xd0(%rbx),%rdi
129d8: 48 89 c1 mov %rax,%rcx
129db: 8b b7 80 03 00 00 mov 0x380(%rdi),%esi
129e1: 85 f6 test %esi,%esi
129e3: 0f 84 8c 00 00 00 je 12a75 <apic_mmio_read+0x133