* Pekka Enberg <penberg@xxxxxxxxxx> wrote:
> Ingo Molnar reported that 'kill -3' didn't work on his machine:
>
> * Ingo Molnar <mingo@xxxxxxx> 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@xxxxxxx>
> Cc: Asias He <asias.hejun@xxxxxxxxx>
> Cc: Avi Kivity <avi@xxxxxxxxxx>
> Cc: Cyrill Gorcunov <gorcunov@xxxxxxxxx>
> Cc: Ingo Molnar <mingo@xxxxxxx>
> Cc: Prasad Joshi <prasadjoshi124@xxxxxxxxx>
> Cc: Sasha Levin <levinsasha928@xxxxxxxxx>
> Signed-off-by: Pekka Enberg <penberg@xxxxxxxxxx>
> ---
> 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@xxxxxxx>
---
diff --git a/tools/kvm/include/kvm/mutex.h b/tools/kvm/include/kvm/mutex.h
index 006ade3..bd765c4 100644
--- a/tools/kvm/include/kvm/mutex.h
+++ b/tools/kvm/include/kvm/mutex.h
@@ -5,6 +5,13 @@
#include "kvm/util.h"
+/*
+ * Kernel-alike mutex API - to make it easier for kernel developers
+ * to write user-space code! :-)
+ */
+
+#define DEFINE_MUTEX(mutex) pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER
+
static inline void mutex_lock(pthread_mutex_t *mutex)
{
if (pthread_mutex_lock(mutex) != 0)
diff --git a/tools/kvm/kvm-cpu.c b/tools/kvm/kvm-cpu.c
index d7febb3..a05ee5a 100644
--- a/tools/kvm/kvm-cpu.c
+++ b/tools/kvm/kvm-cpu.c
@@ -200,7 +200,7 @@ void kvm_cpu__reset_vcpu(struct kvm_cpu *self)
static void print_dtable(const char *name, struct kvm_dtable *dtable)
{
- printf(" %s %016llx %08hx\n",
+ printf(" %s %016llx %08hx\n",
name, (u64) dtable->base, (u16) dtable->limit);
}
@@ -238,11 +238,12 @@ void kvm_cpu__show_registers(struct kvm_cpu *self)
r10 = regs.r10; r11 = regs.r11; r12 = regs.r12;
r13 = regs.r13; r14 = regs.r14; r15 = regs.r15;
- printf("Registers:\n");
+ printf("\n Registers:\n");
+ printf( " ----------\n");
printf(" rip: %016lx rsp: %016lx flags: %016lx\n", rip, rsp, rflags);
printf(" rax: %016lx rbx: %016lx rcx: %016lx\n", rax, rbx, rcx);
printf(" rdx: %016lx rsi: %016lx rdi: %016lx\n", rdx, rsi, rdi);
- printf(" rbp: %016lx r8: %016lx r9: %016lx\n", rbp, r8, r9);
+ printf(" rbp: %016lx r8: %016lx r9: %016lx\n", rbp, r8, r9);
printf(" r10: %016lx r11: %016lx r12: %016lx\n", r10, r11, r12);
printf(" r13: %016lx r14: %016lx r15: %016lx\n", r13, r14, r15);
@@ -254,7 +255,8 @@ void kvm_cpu__show_registers(struct kvm_cpu *self)
printf(" cr0: %016lx cr2: %016lx cr3: %016lx\n", cr0, cr2, cr3);
printf(" cr4: %016lx cr8: %016lx\n", cr4, cr8);
- printf("Segment registers:\n");
+ printf("\n Segment registers:\n");
+ printf( " ------------------\n");
printf(" register selector base limit type p dpl db s l g avl\n");
print_segment("cs ", &sregs.cs);
print_segment("ss ", &sregs.ss);
@@ -266,13 +268,17 @@ void kvm_cpu__show_registers(struct kvm_cpu *self)
print_segment("ldt", &sregs.ldt);
print_dtable("gdt", &sregs.gdt);
print_dtable("idt", &sregs.idt);
- printf(" [ efer: %016llx apic base: %016llx nmi: %s ]\n",
+
+ printf("\n APIC:\n");
+ printf( " -----\n");
+ printf(" efer: %016llx apic base: %016llx nmi: %s\n",
(u64) sregs.efer, (u64) sregs.apic_base,
(self->kvm->nmi_disabled ? "disabled" : "enabled"));
- printf("Interrupt bitmap:\n");
- printf(" ");
+
+ printf("\n Interrupt bitmap:\n");
+ printf( " -----------------\n");
for (i = 0; i < (KVM_NR_INTERRUPTS + 63) / 64; i++)
- printf("%016llx ", (u64) sregs.interrupt_bitmap[i]);
+ printf(" %016llx", (u64) sregs.interrupt_bitmap[i]);
printf("\n");
}
@@ -293,7 +299,8 @@ void kvm_cpu__show_code(struct kvm_cpu *self)
ip = guest_flat_to_host(self->kvm, ip_to_flat(self, self->regs.rip) - code_prologue);
- printf("Code: ");
+ printf("\n Code:\n");
+ printf( " -----\n");
for (i = 0; i < code_len; i++, ip++) {
if (!host_ptr_in_ram(self->kvm, ip))
@@ -302,14 +309,15 @@ void kvm_cpu__show_code(struct kvm_cpu *self)
c = *ip;
if (ip == guest_flat_to_host(self->kvm, ip_to_flat(self, self->regs.rip)))
- printf("<%02x> ", c);
+ printf(" <%02x>", c);
else
- printf("%02x ", c);
+ printf(" %02x", c);
}
printf("\n");
- printf("Stack:\n");
+ printf("\n Stack:\n");
+ printf( " ------\n");
kvm__dump_mem(self->kvm, self->regs.rsp, 32);
}
diff --git a/tools/kvm/kvm-run.c b/tools/kvm/kvm-run.c
index 58e2977..221435d 100644
--- a/tools/kvm/kvm-run.c
+++ b/tools/kvm/kvm-run.c
@@ -29,6 +29,7 @@
/* header files for gitish interface */
#include <kvm/kvm-run.h>
#include <kvm/parse-options.h>
+#include <kvm/mutex.h>
#define DEFAULT_KVM_DEV "/dev/kvm"
#define DEFAULT_CONSOLE "serial"
@@ -127,6 +128,12 @@ static const struct option options[] = {
OPT_END()
};
+/*
+ * Serialize debug printout so that the output of multiple vcpus does not
+ * get mixed up:
+ */
+static DEFINE_MUTEX(printout_mutex);
+
static void handle_sigusr1(int sig)
{
struct kvm_cpu *cpu = current_kvm_cpu;
@@ -134,9 +141,13 @@ static void handle_sigusr1(int sig)
if (!cpu)
return;
+ mutex_lock(&printout_mutex);
+ printf("\n#\n# vCPU #%ld's dump:\n#\n", cpu->cpu_id);
kvm_cpu__show_registers(cpu);
kvm_cpu__show_code(cpu);
kvm_cpu__show_page_tables(cpu);
+ fflush(stdout);
+ mutex_unlock(&printout_mutex);
}
static void handle_sigquit(int sig)
--
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
