From e91d7402d574b4067cb61692c6e4e747f1cab051 Mon Sep 17 00:00:00 2001 From: Sainath Grandhi Date: Wed, 27 Mar 2019 09:10:29 -0700 Subject: [PATCH] hv: Debug messages from a CPU are overlapped with other CPUs messages In the cases when more than one CPU has something to print, exception dump from one CPU is overlapped with other CPU's messages and the final text that is printed on console is all mixed up and does not make any sense. Changing printf to pr_err so that the messages are printed one after the other. Tracked-On: #2858 Signed-off-by: Sainath Grandhi Reviewed-by: Eddie Dong --- hypervisor/debug/dump.c | 88 ++++++++++++++++++++--------------------- 1 file changed, 44 insertions(+), 44 deletions(-) diff --git a/hypervisor/debug/dump.c b/hypervisor/debug/dump.c index 4faf83b43..e8e93a0d3 100644 --- a/hypervisor/debug/dump.c +++ b/hypervisor/debug/dump.c @@ -66,49 +66,49 @@ struct intr_excp_ctx *crash_ctx; static void dump_guest_reg(struct acrn_vcpu *vcpu) { - printf("\n\n================================================"); - printf("================================\n\n"); - printf("Guest Registers:\r\n"); - printf("= VM ID %d ==== vCPU ID %hu === pCPU ID %d ====" + pr_acrnlog("\n\n================================================"); + pr_acrnlog("================================\n\n"); + pr_acrnlog("Guest Registers:\r\n"); + pr_acrnlog("= VM ID %d ==== vCPU ID %hu === pCPU ID %d ====" "world %d =============\r\n", vcpu->vm->vm_id, vcpu->vcpu_id, vcpu->pcpu_id, vcpu->arch.cur_context); - printf("= RIP=0x%016llx RSP=0x%016llx " + pr_acrnlog("= RIP=0x%016llx RSP=0x%016llx " "RFLAGS=0x%016llx\r\n", vcpu_get_rip(vcpu), vcpu_get_gpreg(vcpu, CPU_REG_RSP), vcpu_get_rflags(vcpu)); - printf("= CR0=0x%016llx CR2=0x%016llx " + pr_acrnlog("= CR0=0x%016llx CR2=0x%016llx " " CR3=0x%016llx\r\n", vcpu_get_cr0(vcpu), vcpu_get_cr2(vcpu), exec_vmread(VMX_GUEST_CR3)); - printf("= RAX=0x%016llx RBX=0x%016llx " + pr_acrnlog("= RAX=0x%016llx RBX=0x%016llx " "RCX=0x%016llx\r\n", vcpu_get_gpreg(vcpu, CPU_REG_RAX), vcpu_get_gpreg(vcpu, CPU_REG_RBX), vcpu_get_gpreg(vcpu, CPU_REG_RCX)); - printf("= RDX=0x%016llx RDI=0x%016llx " + pr_acrnlog("= RDX=0x%016llx RDI=0x%016llx " "RSI=0x%016llx\r\n", vcpu_get_gpreg(vcpu, CPU_REG_RDX), vcpu_get_gpreg(vcpu, CPU_REG_RDI), vcpu_get_gpreg(vcpu, CPU_REG_RSI)); - printf("= RBP=0x%016llx R8=0x%016llx " + pr_acrnlog("= RBP=0x%016llx R8=0x%016llx " "R9=0x%016llx\r\n", vcpu_get_gpreg(vcpu, CPU_REG_RBP), vcpu_get_gpreg(vcpu, CPU_REG_R8), vcpu_get_gpreg(vcpu, CPU_REG_R9)); - printf("= R10=0x%016llx R11=0x%016llx " + pr_acrnlog("= R10=0x%016llx R11=0x%016llx " "R12=0x%016llx\r\n", vcpu_get_gpreg(vcpu, CPU_REG_R10), vcpu_get_gpreg(vcpu, CPU_REG_R11), vcpu_get_gpreg(vcpu, CPU_REG_R12)); - printf("= R13=0x%016llx R14=0x%016llx " + pr_acrnlog("= R13=0x%016llx R14=0x%016llx " "R15=0x%016llx\r\n", vcpu_get_gpreg(vcpu, CPU_REG_R13), vcpu_get_gpreg(vcpu, CPU_REG_R14), vcpu_get_gpreg(vcpu, CPU_REG_R15)); - printf("\r\n"); + pr_acrnlog("\r\n"); } static void dump_guest_stack(struct acrn_vcpu *vcpu) @@ -119,21 +119,21 @@ static void dump_guest_stack(struct acrn_vcpu *vcpu) if (copy_from_gva(vcpu, tmp, vcpu_get_gpreg(vcpu, CPU_REG_RSP), DUMP_STACK_SIZE, &err_code, &fault_addr) < 0) { - printf("\r\nUnabled to Copy Guest Stack:\r\n"); + pr_acrnlog("\r\nUnabled to Copy Guest Stack:\r\n"); return; } - printf("\r\nGuest Stack:\r\n"); - printf("Dump stack for vcpu %hu, from gva 0x%016llx\r\n", + pr_acrnlog("\r\nGuest Stack:\r\n"); + pr_acrnlog("Dump stack for vcpu %hu, from gva 0x%016llx\r\n", vcpu->vcpu_id, vcpu_get_gpreg(vcpu, CPU_REG_RSP)); for (i = 0U; i < (DUMP_STACK_SIZE >> 5U); i++) { - printf("guest_rsp(0x%llx): 0x%016llx 0x%016llx " + pr_acrnlog("guest_rsp(0x%llx): 0x%016llx 0x%016llx " "0x%016llx 0x%016llx\r\n", (vcpu_get_gpreg(vcpu, CPU_REG_RSP)+(i*32U)), tmp[i*4], tmp[(i*4)+1], tmp[(i*4)+2], tmp[(i*4)+3]); } - printf("\r\n"); + pr_acrnlog("\r\n"); } static void show_guest_call_trace(struct acrn_vcpu *vcpu) @@ -144,8 +144,8 @@ static void show_guest_call_trace(struct acrn_vcpu *vcpu) uint32_t err_code; bp = vcpu_get_gpreg(vcpu, CPU_REG_RBP); - printf("Guest Call Trace: **************************************\r\n"); - printf("Maybe the call trace is not accurate, pls check stack!!\r\n"); + pr_acrnlog("Guest Call Trace: **************************************\r\n"); + pr_acrnlog("Maybe the call trace is not accurate, pls check stack!!\r\n"); /* if enable compiler option(no-omit-frame-pointer) the stack layout * should be like this when call a function for x86_64 * @@ -166,16 +166,16 @@ static void show_guest_call_trace(struct acrn_vcpu *vcpu) err = copy_from_gva(vcpu, &parent_bp, bp, sizeof(parent_bp), &err_code, &fault_addr); if (err < 0) { - printf("\r\nUnabled to get Guest parent BP\r\n"); + pr_acrnlog("\r\nUnabled to get Guest parent BP\r\n"); return; } - printf("BP_GVA(0x%016llx) RIP=0x%016llx\r\n", bp, parent_bp); + pr_acrnlog("BP_GVA(0x%016llx) RIP=0x%016llx\r\n", bp, parent_bp); /* Get previous rbp*/ bp = parent_bp; count++; } - printf("\r\n"); + pr_acrnlog("\r\n"); } static void dump_guest_context(uint16_t pcpu_id) @@ -197,16 +197,16 @@ static void show_host_call_trace(uint64_t rsp, uint64_t rbp_arg, uint16_t pcpu_i uint32_t cb_hierarchy = 0U; uint64_t *sp = (uint64_t *)rsp; - printf("\r\nHost Stack: CPU_ID = %hu\r\n", pcpu_id); + pr_acrnlog("\r\nHost Stack: CPU_ID = %hu\r\n", pcpu_id); for (i = 0U; i < (DUMP_STACK_SIZE >> 5U); i++) { - printf("addr(0x%llx) 0x%016llx 0x%016llx 0x%016llx " + pr_acrnlog("addr(0x%llx) 0x%016llx 0x%016llx 0x%016llx " "0x%016llx\r\n", (rsp + (i * 32U)), sp[i * 4U], sp[(i * 4U) + 1U], sp[(i * 4U) + 2U], sp[(i * 4U) + 3U]); } - printf("\r\n"); + pr_acrnlog("\r\n"); - printf("Host Call Trace:\r\n"); + pr_acrnlog("Host Call Trace:\r\n"); /* if enable compiler option(no-omit-frame-pointer) the stack layout * should be like this when call a function for x86_64 @@ -226,12 +226,12 @@ static void show_host_call_trace(uint64_t rsp, uint64_t rbp_arg, uint16_t pcpu_i if (return_address == SP_BOTTOM_MAGIC) { break; } - printf("----> 0x%016llx\r\n", + pr_acrnlog("----> 0x%016llx\r\n", *(uint64_t *)(rbp + sizeof(uint64_t))); rbp = *(uint64_t *)rbp; cb_hierarchy++; } - printf("\r\n"); + pr_acrnlog("\r\n"); } void asm_assert(int32_t line, const char *file, const char *txt) @@ -240,7 +240,7 @@ void asm_assert(int32_t line, const char *file, const char *txt) uint64_t rsp = cpu_rsp_get(); uint64_t rbp = cpu_rbp_get(); - printf("Assertion failed in file %s,line %d : %s", + pr_acrnlog("Assertion failed in file %s,line %d : %s", file, line, txt); show_host_call_trace(rsp, rbp, pcpu_id); dump_guest_context(pcpu_id); @@ -253,35 +253,35 @@ void dump_intr_excp_frame(const struct intr_excp_ctx *ctx) { const char *name = "Not defined"; - printf("\n\n================================================"); - printf("================================\n=\n"); + pr_acrnlog("\n\n================================================"); + pr_acrnlog("================================\n=\n"); if (ctx->vector < 0x20UL) { name = excp_names[ctx->vector]; - printf("= Unhandled exception: %d (%s)\n", ctx->vector, name); + pr_acrnlog("= Unhandled exception: %d (%s)\n", ctx->vector, name); } /* Dump host register*/ - printf("\r\nHost Registers:\r\n"); - printf("= Vector=0x%016llX RIP=0x%016llX\n", + pr_acrnlog("\r\nHost Registers:\r\n"); + pr_acrnlog("= Vector=0x%016llX RIP=0x%016llX\n", ctx->vector, ctx->rip); - printf("= RAX=0x%016llX RBX=0x%016llX RCX=0x%016llX\n", + pr_acrnlog("= RAX=0x%016llX RBX=0x%016llX RCX=0x%016llX\n", ctx->gp_regs.rax, ctx->gp_regs.rbx, ctx->gp_regs.rcx); - printf("= RDX=0x%016llX RDI=0x%016llX RSI=0x%016llX\n", + pr_acrnlog("= RDX=0x%016llX RDI=0x%016llX RSI=0x%016llX\n", ctx->gp_regs.rdx, ctx->gp_regs.rdi, ctx->gp_regs.rsi); - printf("= RSP=0x%016llX RBP=0x%016llX RBX=0x%016llX\n", + pr_acrnlog("= RSP=0x%016llX RBP=0x%016llX RBX=0x%016llX\n", ctx->gp_regs.rsp, ctx->gp_regs.rbp, ctx->gp_regs.rbx); - printf("= R8=0x%016llX R9=0x%016llX R10=0x%016llX\n", + pr_acrnlog("= R8=0x%016llX R9=0x%016llX R10=0x%016llX\n", ctx->gp_regs.r8, ctx->gp_regs.r9, ctx->gp_regs.r10); - printf("= R11=0x%016llX R12=0x%016llX R13=0x%016llX\n", + pr_acrnlog("= R11=0x%016llX R12=0x%016llX R13=0x%016llX\n", ctx->gp_regs.r11, ctx->gp_regs.r12, ctx->gp_regs.r13); - printf("= RFLAGS=0x%016llX R14=0x%016llX R15=0x%016llX\n", + pr_acrnlog("= RFLAGS=0x%016llX R14=0x%016llX R15=0x%016llX\n", ctx->rflags, ctx->gp_regs.r14, ctx->gp_regs.r15); - printf("= ERRCODE=0x%016llX CS=0x%016llX SS=0x%016llX\n", + pr_acrnlog("= ERRCODE=0x%016llX CS=0x%016llX SS=0x%016llX\n", ctx->error_code, ctx->cs, ctx->ss); - printf("\r\n"); + pr_acrnlog("\r\n"); - printf("====================================================="); - printf("===========================\n"); + pr_acrnlog("====================================================="); + pr_acrnlog("===========================\n"); } void dump_exception(struct intr_excp_ctx *ctx, uint16_t pcpu_id)