qemu-devel
[Top][All Lists]
Advanced

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

Re: [Qemu-devel] race between kvm-kmod-3.0 and kvm-kmod-3.3 // was: race


From: Peter Lieven
Subject: Re: [Qemu-devel] race between kvm-kmod-3.0 and kvm-kmod-3.3 // was: race condition in qemu-kvm-1.0.1
Date: Thu, 28 Jun 2012 12:34:54 +0200
User-agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.23) Gecko/20110921 Thunderbird/3.1.15

On 28.06.2012 11:39, Jan Kiszka wrote:
On 2012-06-28 11:31, Peter Lieven wrote:
On 28.06.2012 11:21, Jan Kiszka wrote:
On 2012-06-28 11:11, Peter Lieven wrote:
On 27.06.2012 18:54, Jan Kiszka wrote:
On 2012-06-27 17:39, Peter Lieven wrote:
Hi all,

i debugged this further and found out that kvm-kmod-3.0 is working with
qemu-kvm-1.0.1 while kvm-kmod-3.3 and kvm-kmod-3.4 are not. What is
working as well is kvm-kmod-3.4 with an old userspace (qemu-kvm-0.13.0).
Has anyone a clue which new KVM feature could cause this if a vcpu is in
an infinite loop?
Before accusing kvm-kmod ;), can you check if the effect is visible with
an original Linux 3.3.x or 3.4.x kernel as well?
sorry, i should have been more specific. maybe I also misunderstood sth.
I was believing that kvm-kmod-3.0 is basically what is in vanialla kernel
3.0. If I use the ubuntu kernel from ubuntu oneiric (3.0.0) it works, if
I use
a self-compiled kvm-kmod-3.3/3.4 with that kernel it doesn't.
however, maybe we don't have to dig to deep - see below.
kvm-kmod wraps and patches things to make the kvm code from 3.3/3.4
working on an older kernel. This step may introduce bugs of its own.
Therefore my suggestion to use a "real" 3.x kernel to exclude that risk
first of all.

Then, bisection the change in qemu-kvm that apparently resolved the
issue would be interesting.

If we have to dig deeper, tracing [1] the lockup would likely be helpful
(all events of the qemu process, not just KVM related ones: trace-cmd
record -e all qemu-system-x86_64 ...).
that here is bascially whats going on:

    qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio read
len 3 gpa 0xa0000 val 0x10ff
      qemu-kvm-1.0-2506  [010] 60996.908000: vcpu_match_mmio:      gva
0xa0000 gpa 0xa0000 Read GPA
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
unsatisfied-read len 1 gpa 0xa0000 val 0x0
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_userspace_exit:   reason
KVM_EXIT_MMIO (6)
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
read len 3 gpa 0xa0000 val 0x10ff
      qemu-kvm-1.0-2506  [010] 60996.908000: vcpu_match_mmio:      gva
0xa0000 gpa 0xa0000 Read GPA
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
unsatisfied-read len 1 gpa 0xa0000 val 0x0
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_userspace_exit:   reason
KVM_EXIT_MMIO (6)
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
read len 3 gpa 0xa0000 val 0x10ff
      qemu-kvm-1.0-2506  [010] 60996.908000: vcpu_match_mmio:      gva
0xa0000 gpa 0xa0000 Read GPA
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
unsatisfied-read len 1 gpa 0xa0000 val 0x0
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_userspace_exit:   reason
KVM_EXIT_MMIO (6)
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
read len 3 gpa 0xa0000 val 0x10ff
      qemu-kvm-1.0-2506  [010] 60996.908000: vcpu_match_mmio:      gva
0xa0000 gpa 0xa0000 Read GPA
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_mmio:             mmio
unsatisfied-read len 1 gpa 0xa0000 val 0x0
      qemu-kvm-1.0-2506  [010] 60996.908000: kvm_userspace_exit:   reason
KVM_EXIT_MMIO (6)

its doing that forever. this is tracing the kvm module. doing the
qemu-system-x86_64 trace is a bit compilcated, but
maybe this is already sufficient. otherwise i will of course gather this
info as well.
That's only tracing KVM event, and it's tracing when things went wrong
already. We may need a full trace (-e all) specifically for the period
when this pattern above started.
i will do that. maybe i should explain that the vcpu is executing
garbage when this above starts. its basically booting from an empty
harddisk.

if i understand correctly qemu-kvm loops in kvm_cpu_exec(CPUState *env);

maybe the time to handle the monitor/qmp connection is just to short.
if i understand furhter correctly, it can only handle monitor connections
while qemu-kvm is executing kvm_vcpu_ioctl(env, KVM_RUN, 0); or am i
wrong here? the time spend in this state might be rather short.
Unless you played with priorities and affinities, the Linux scheduler
should provide the required time to the iothread.

my concern is not that the machine hangs, just the the hypervisor is
unresponsive
and its impossible to reset or quit gracefully. the only way to get the
hypervisor
ended is via SIGKILL.
Right. Even if the guest runs wild, you must be able to control the vm
via the monitor etc. If not, that's a bug.
what i observed just know is that the monitor is working up to the
point i try to quit the hypervisor or try to reset the cpu.

so we where looking at a completely wrong place...

it seems that in this short excerpt, that the deadlock appears not
on excution but when the vcpus shall be paused.

Program received signal SIGINT, Interrupt.
0x00007fc8ec36785c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) thread apply all bt

Thread 4 (Thread 0x7fc8eb5a9700 (LWP 731)):
#0  0x00007fc8ec0b7747 in ioctl () from /lib/libc.so.6
#1 0x00007fc8ed92eedc in kvm_vcpu_ioctl (env=0x7fc8ef6c4b80, type=44672) at /usr/src/qemu-kvm-1.0.1/kvm-all.c:1101 #2 0x00007fc8ed92e936 in kvm_cpu_exec (env=0x7fc8ef6c4b80) at /usr/src/qemu-kvm-1.0.1/kvm-all.c:987 #3 0x00007fc8ed8fd2b4 in qemu_kvm_cpu_thread_fn (arg=0x7fc8ef6c4b80) at /usr/src/qemu-kvm-1.0.1/cpus.c:740
#4  0x00007fc8ec3629ca in start_thread () from /lib/libpthread.so.0
#5  0x00007fc8ec0bfcdd in clone () from /lib/libc.so.6
#6  0x0000000000000000 in ?? ()

Thread 3 (Thread 0x7fc8eada8700 (LWP 732)):
#0 0x00007fc8ec36785c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #1 0x00007fc8ed882189 in qemu_cond_wait (cond=0x7fc8ef6ead00, mutex=0x7fc8ee4f2940) at qemu-thread-posix.c:113 #2 0x00007fc8ed8fd1b7 in qemu_kvm_wait_io_event (env=0x7fc8ef6dcae0) at /usr/src/qemu-kvm-1.0.1/cpus.c:710 #3 0x00007fc8ed8fd2d8 in qemu_kvm_cpu_thread_fn (arg=0x7fc8ef6dcae0) at /usr/src/qemu-kvm-1.0.1/cpus.c:745
#4  0x00007fc8ec3629ca in start_thread () from /lib/libpthread.so.0
#5  0x00007fc8ec0bfcdd in clone () from /lib/libc.so.6
#6  0x0000000000000000 in ?? ()

Thread 2 (Thread 0x7fc8a8fae700 (LWP 733)):
#0 0x00007fc8ec36785c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #1 0x00007fc8ed882189 in qemu_cond_wait (cond=0x7fc8efb54550, mutex=0x7fc8efb54580) at qemu-thread-posix.c:113 #2 0x00007fc8ed8b7d49 in vnc_worker_thread_loop (queue=0x7fc8efb54550) at ui/vnc-jobs-async.c:222 #3 0x00007fc8ed8b8227 in vnc_worker_thread (arg=0x7fc8efb54550) at ui/vnc-jobs-async.c:318
#4  0x00007fc8ec3629ca in start_thread () from /lib/libpthread.so.0
#5  0x00007fc8ec0bfcdd in clone () from /lib/libc.so.6
#6  0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fc8ed718700 (LWP 725)):
#0 0x00007fc8ec36785c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #1 0x00007fc8ed882189 in qemu_cond_wait (cond=0x7fc8ee16a120, mutex=0x7fc8ee4f2940) at qemu-thread-posix.c:113 #2 0x00007fc8ed8fd67b in pause_all_vcpus () at /usr/src/qemu-kvm-1.0.1/cpus.c:881 #3 0x00007fc8ed8548cd in main (argc=38, argv=0x7fffcde70a48, envp=0x7fffcde70b80) at /usr/src/qemu-kvm-1.0.1/vl.c:3525
(gdb) q

Peter



reply via email to

[Prev in Thread] Current Thread [Next in Thread]