]> git.karo-electronics.de Git - karo-tx-linux.git/commit
kvm tools: Fix and improve the CPU register dump debug output code
authorIngo Molnar <mingo@elte.hu>
Mon, 9 May 2011 07:27:11 +0000 (09:27 +0200)
committerPekka Enberg <penberg@kernel.org>
Mon, 9 May 2011 14:31:12 +0000 (17:31 +0300)
commit4cd62c73f933334427a548fa0bfcf6da27971975
tree091e3c4f00422123bb6ae1bbb7ee75c5a29b9d1e
parent0f9e3d8506d92cda443eac3d812889c73658e69e
kvm tools: Fix and improve the CPU register dump debug output code

* Pekka Enberg <penberg@kernel.org> wrote:

> Ingo Molnar reported that 'kill -3' didn't work on his machine:
>
>   * Ingo Molnar <mingo@elte.hu> wrote:
>
>   > This is really cumbersome to debug - is there some good way to get to the RIP
>   > that the guest is hanging in? If kvm would print that out to the host console
>   > (even if it's just the raw RIP initially) on a kill -3 that would help
>   > enormously.
>
>   Looks like the code should be doing that already - but the ioctl(KVM_GET_SREGS)
>   hangs:
>
>     [pid   748] ioctl(6, KVM_GET_SREGS
>
> Avi Kivity pointed out that it's not safe to call KVM_GET_SREGS (or other vcpu
> related ioctls) from other threads:
>
>   > is it not OK to call KVM_GET_SREGS from other threads than the one
>   > that's doing KVM_RUN?
>
>   From Documentation/kvm/api.txt:
>
>    - vcpu ioctls: These query and set attributes that control the operation
>      of a single virtual cpu.
>
>      Only run vcpu ioctls from the same thread that was used to create the
>      vcpu.
>
> Fix that up by using pthread_kill() to force the threads that are doing KVM_RUN
> to do the register dumps.
>
> Reported: Ingo Molnar <mingo@elte.hu>
> Cc: Asias He <asias.hejun@gmail.com>
> Cc: Avi Kivity <avi@redhat.com>
> Cc: Cyrill Gorcunov <gorcunov@gmail.com>
> Cc: Ingo Molnar <mingo@elte.hu>
> Cc: Prasad Joshi <prasadjoshi124@gmail.com>
> Cc: Sasha Levin <levinsasha928@gmail.com>
> Signed-off-by: Pekka Enberg <penberg@kernel.org>
> ---
>  tools/kvm/kvm-run.c |   20 +++++++++++++++++---
>  1 files changed, 17 insertions(+), 3 deletions(-)
>
> diff --git a/tools/kvm/kvm-run.c b/tools/kvm/kvm-run.c
> index eb50b6a..58e2977 100644
> --- a/tools/kvm/kvm-run.c
> +++ b/tools/kvm/kvm-run.c
> @@ -127,6 +127,18 @@ static const struct option options[] = {
>   OPT_END()
>  };
>
> +static void handle_sigusr1(int sig)
> +{
> + struct kvm_cpu *cpu = current_kvm_cpu;
> +
> + if (!cpu)
> + return;
> +
> + kvm_cpu__show_registers(cpu);
> + kvm_cpu__show_code(cpu);
> + kvm_cpu__show_page_tables(cpu);
> +}
> +
>  static void handle_sigquit(int sig)
>  {
>   int i;
> @@ -134,9 +146,10 @@ static void handle_sigquit(int sig)
>   for (i = 0; i < nrcpus; i++) {
>   struct kvm_cpu *cpu = kvm_cpus[i];
>
> - kvm_cpu__show_registers(cpu);
> - kvm_cpu__show_code(cpu);
> - kvm_cpu__show_page_tables(cpu);
> + if (!cpu)
> + continue;
> +
> + pthread_kill(cpu->thread, SIGUSR1);
>   }
>
>   serial8250__inject_sysrq(kvm);

i can see a couple of problems with the debug printout code, which currently
produces a stream of such dumps for each vcpu:

Registers:
 rip: 0000000000000000   rsp: 00000000000016ca flags: 0000000000010002
 rax: 0000000000000000   rbx: 0000000000000000   rcx: 0000000000000000
 rdx: 0000000000000000   rsi: 0000000000000000   rdi: 0000000000000000
 rbp: 0000000000008000   r8:  0000000000000000   r9:  0000000000000000
 r10: 0000000000000000   r11: 0000000000000000   r12: 0000000000000000
 r13: 0000000000000000   r14: 0000000000000000   r15: 0000000000000000
 cr0: 0000000060000010   cr2: 0000000000000070   cr3: 0000000000000000
 cr4: 0000000000000000   cr8: 0000000000000000
Segment registers:
 register  selector  base              limit     type  p dpl db s l g avl
 cs        f000      00000000000f0000  0000ffff  03    1 3   0  1 0 0 0
 ss        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 ds        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 es        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 fs        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 gs        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 tr        0000      0000000000000000  0000ffff  0b    1 0   0  0 0 0 0
 ldt       0000      0000000000000000  0000ffff  02    1 0   0  0 0 0 0
 gdt                 0000000000000000 0000ffff
 idt                 0000000000000000 0000ffff
 [ efer: 0000000000000000  apic base: 00000000fee00900  nmi: enabled ]
Interrupt bitmap:
 0000000000000000 0000000000000000 0000000000000000 0000000000000000
Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <cf> eb 0d 90 90 90 90 90 90 90 90 90 90 90 90 90 f6 c4 0e 75 4b
Stack:
  0x000016ca: 00 00 00 00  00 00 00 00
  0x000016d2: 00 00 00 00  00 00 00 00
  0x000016da: 00 00 00 00  00 00 00 00
  0x000016e2: 00 00 00 00  00 00 00 00

The problems are:

 - This does not work very well on SMP with lots of vcpus, because the printing
   is unserialized, resulting in a jumbled mess of an output, all vcpus trying
   to print to the console at once, often mixing lines and characters randomly.

 - stdout from a signal handler must be flushed, otherwise lines can remain
   buffered if someone saves the output via 'tee' for example.

 - the dumps from the various CPUs are not distinguishable - they are just
   dumped after each other with no identification

 - the various printouts are rather hard to parse visually - it's not easy to see
   various properties "at a glance" because the dump is visually confusing.

The patch below addresses these concerns, serializes the output, tidies up the
printout, resulting in this new output:

#
# vCPU #0's dump:
#

 Registers:
 ----------
 rip: 0000000000000000   rsp: 00000000000008bc flags: 0000000000010002
 rax: 0000000000000000   rbx: 0000000000000000   rcx: 0000000000000000
 rdx: 0000000000000000   rsi: 0000000000000000   rdi: 0000000000000000
 rbp: 0000000000008000    r8: 0000000000000000    r9: 0000000000000000
 r10: 0000000000000000   r11: 0000000000000000   r12: 0000000000000000
 r13: 0000000000000000   r14: 0000000000000000   r15: 0000000000000000
 cr0: 0000000060000010   cr2: 0000000000000070   cr3: 0000000000000000
 cr4: 0000000000000000   cr8: 0000000000000000

 Segment registers:
 ------------------
 register  selector  base              limit     type  p dpl db s l g avl
 cs        f000      00000000000f0000  0000ffff  03    1 3   0  1 0 0 0
 ss        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 ds        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 es        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 fs        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 gs        1000      0000000000010000  0000ffff  03    1 3   0  1 0 0 0
 tr        0000      0000000000000000  0000ffff  0b    1 0   0  0 0 0 0
 ldt       0000      0000000000000000  0000ffff  02    1 0   0  0 0 0 0
 gdt                 0000000000000000  0000ffff
 idt                 0000000000000000  0000ffff

 APIC:
 -----
 efer: 0000000000000000  apic base: 00000000fee00900  nmi: enabled

 Interrupt bitmap:
 -----------------
 0000000000000000 0000000000000000 0000000000000000 0000000000000000

 Code:
 -----
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <cf> eb 0d 90 90 90 90 90 90 90 90 90 90 90 90 90 f6 c4 0e 75 4b

 Stack:
 ------
  0x000008bc: 00 00 00 00  00 00 00 00
  0x000008c4: 00 00 00 00  00 00 00 00
  0x000008cc: 00 00 00 00  00 00 00 00
  0x000008d4: 00 00 00 00  00 00 00 00

Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Pekka Enberg <penberg@kernel.org>
tools/kvm/include/kvm/mutex.h
tools/kvm/kvm-cpu.c
tools/kvm/kvm-run.c