[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: [Xen-devel] [PATCH for-4.5 v6 06/16] xen: Convert vmware_port to xentrace usage
- To: Don Slutz <dslutz@xxxxxxxxxxx>, <xen-devel@xxxxxxxxxxxxx>
- From: George Dunlap <george.dunlap@xxxxxxxxxxxxx>
- Date: Wed, 24 Sep 2014 18:27:57 +0100
- Cc: Kevin Tian <kevin.tian@xxxxxxxxx>, Keir Fraser <keir@xxxxxxx>, Ian Campbell <ian.campbell@xxxxxxxxxx>, Stefano Stabellini <stefano.stabellini@xxxxxxxxxxxxx>, Jun Nakajima <jun.nakajima@xxxxxxxxx>, Eddie Dong <eddie.dong@xxxxxxxxx>, Ian Jackson <ian.jackson@xxxxxxxxxxxxx>, Tim Deegan <tim@xxxxxxx>, Aravind Gopalakrishnan <Aravind.Gopalakrishnan@xxxxxxx>, Jan Beulich <jbeulich@xxxxxxxx>, Andrew Cooper <andrew.cooper3@xxxxxxxxxx>, Boris Ostrovsky <boris.ostrovsky@xxxxxxxxxx>, Suravee Suthikulpanit <suravee.suthikulpanit@xxxxxxx>
- Delivery-date: Wed, 24 Sep 2014 17:28:44 +0000
- List-id: Xen developer discussion <xen-devel.lists.xen.org>
On 09/20/2014 07:07 PM, Don Slutz wrote:
Reduce the VMPORT_DBG_LOG calls.
You should also have mentioned that you added hew HVMTRACE macros which
will log the TSC value.
The reason the HVMTRACE macros don't log the TSC values is that for the
most part you can get all the timing information you need from the TSC
on the vmexit and vmenter. Looking at where you've added the TSC
values, I don't really see how it adds anything except bloat to the
log. Is there a reason you need to know exactly when these different
things happened, instead of just being able to bracket them between
VMENTER and VMEXITs?
Signed-off-by: Don Slutz <dslutz@xxxxxxxxxxx>
---
v6:
Dropped the attempt to use svm_nextrip_insn_length via
__get_instruction_length (added in v2). Just always look
at upto 15 bytes on AMD.
v5:
exitinfo1 is used twice.
Fixed.
xen/arch/x86/hvm/svm/svm.c | 20 ++++++++++++++---
xen/arch/x86/hvm/vmware/vmport.c | 48 ++++++++++++++++++++++------------------
xen/arch/x86/hvm/vmx/vmx.c | 12 ++++++++++
xen/include/asm-x86/hvm/trace.h | 45 +++++++++++++++++++++++++++++++++++++
xen/include/asm-x86/hvm/vmport.h | 6 -----
xen/include/public/trace.h | 12 ++++++++++
6 files changed, 113 insertions(+), 30 deletions(-)
diff --git a/xen/arch/x86/hvm/svm/svm.c b/xen/arch/x86/hvm/svm/svm.c
index ea99dfb..716dda1 100644
--- a/xen/arch/x86/hvm/svm/svm.c
+++ b/xen/arch/x86/hvm/svm/svm.c
@@ -2081,10 +2081,18 @@ static void svm_vmexit_gp_intercept(struct
cpu_user_regs *regs,
*/
unsigned long inst_len = 15;
unsigned long inst_addr = svm_rip2pointer(v);
- int rc;
+ uint32_t starting_rdx = regs->rdx;
+ int rc = vmport_gp_check(regs, v, &inst_len, inst_addr,
+ vmcb->exitinfo1, vmcb->exitinfo2);
+
+ if ( hvm_long_mode_enabled(v) )
+ HVMTRACE_LONG2_C4D(TRAP_GP, inst_len, starting_rdx,
+ TRC_PAR_LONG(vmcb->exitinfo1),
+ TRC_PAR_LONG(vmcb->exitinfo2));
+ else
+ HVMTRACE_C4D(TRAP_GP, inst_len, starting_rdx, vmcb->exitinfo1,
+ vmcb->exitinfo2);
- rc = vmport_gp_check(regs, v, &inst_len, inst_addr,
- vmcb->exitinfo1, vmcb->exitinfo2);
if ( !rc )
__update_guest_eip(regs, inst_len);
else
@@ -2097,6 +2105,12 @@ static void svm_vmexit_gp_intercept(struct cpu_user_regs
*regs,
(unsigned long)vmcb->exitinfo2, regs->error_code,
regs->rip, inst_addr, inst_len, regs->rax, regs->rbx,
regs->rcx, regs->rdx, regs->rsi, regs->rdi);
+ if ( hvm_long_mode_enabled(v) )
+ HVMTRACE_LONG_C5D(TRAP_GP_UNKNOWN, rc, regs->rax, regs->rbx,
regs->rcx,
+ TRC_PAR_LONG(inst_addr));
+ else
+ HVMTRACE_C5D(TRAP_GP_UNKNOWN, rc, regs->rax, regs->rbx, regs->rcx,
+ inst_addr);
hvm_inject_hw_exception(TRAP_gp_fault, vmcb->exitinfo1);
}
}
diff --git a/xen/arch/x86/hvm/vmware/vmport.c b/xen/arch/x86/hvm/vmware/vmport.c
index 811c303..962ee32 100644
--- a/xen/arch/x86/hvm/vmware/vmport.c
+++ b/xen/arch/x86/hvm/vmware/vmport.c
@@ -18,6 +18,7 @@
#include <asm/hvm/hvm.h>
#include <asm/hvm/support.h>
#include <asm/hvm/vmport.h>
+#include <asm/hvm/trace.h>
#include "backdoor_def.h"
#include "guest_msg_def.h"
@@ -66,12 +67,15 @@ int vmport_ioport(int dir, uint32_t port, uint32_t bytes,
uint32_t *val)
uint64_t saved_rax = regs->rax;
uint64_t value;
- VMPORT_DBG_LOG(VMPORT_LOG_TRACE,
- "VMware trace dir=%d bytes=%u ip=%"PRIx64" cmd=%d ax=%"
- PRIx64" bx=%"PRIx64" cx=%"PRIx64" dx=%"PRIx64" si=%"
- PRIx64" di=%"PRIx64"\n", dir, bytes,
- regs->rip, cmd, regs->rax, regs->rbx, regs->rcx,
- regs->rdx, regs->rsi, regs->rdi);
+ if ( dir == IOREQ_READ )
+ HVMTRACE_ND(VMPORT_READ_BEFORE, 0, 1/*cycles*/, 6,
+ regs->rax, regs->rbx, regs->rcx,
+ regs->rdx, regs->rsi, regs->rdi);
+ else
+ HVMTRACE_ND(VMPORT_WRITE_AFTER_BEFORE, 0, 1/*cycles*/, 6,
+ regs->rax, regs->rbx, regs->rcx,
+ regs->rdx, regs->rsi, regs->rdi);
Adding trace points in a separate patch is one thing, but adding code
like this and then removing it in a later patch is really poor form; it
could potentially make bisection difficult too, if (for example) the
output is so verbose in that short window as to make it unusable between
those changesets.
I think you should go back to the previous patches and remove all the
VMPORT_DBG_LOG()s that don't survive until the end of the series.
Unless, that is, you think that you might be making the case to accept
patches 1-5 for 4.5 without this patch; in which case it may make sense
to leave it the way it is.
We normally don't log both BEFORE and AFTER states of things like
hypercalls -- just logging the outcome of what the hypervisor did should
be sufficient, shouldn't it? Do you really need to know the value of
things that got clobbered? You've got tracing in the error paths for
when things don't go as you expected.
Also, same comment with the cycles: I don't see any value in logging how
long it took to get from the VMEXIT to here or from here to anywhere
else; it just makes the log really bloated.
+
switch ( cmd )
{
case BDOOR_CMD_GETMHZ:
@@ -143,19 +147,17 @@ int vmport_ioport(int dir, uint32_t port, uint32_t bytes,
uint32_t *val)
regs->rax = 0x0;
break;
default:
- VMPORT_DBG_LOG(VMPORT_LOG_ERROR,
- "VMware bytes=%d dir=%d cmd=%d",
- bytes, dir, cmd);
+ HVMTRACE_ND(VMPORT_UNKNOWN, 0, 1/*cycles*/, 6,
+ (bytes << 8) + dir, cmd, regs->rbx,
+ regs->rcx, regs->rsi, regs->rdi);
You do realize the maximum number of bytes you can log is 7, not 6,
right? The macro stops at 6, but that's just where Keir got tired, I
think; if you want ot log more registers here you can extend it to 7.
Also, I think for clarity you should (bytes << 8) | dir rather than +dir.
break;
}
- VMPORT_DBG_LOG(VMPORT_LOG_VMWARE_AFTER,
- "VMware after ip=%"PRIx64" cmd=%d ax=%"PRIx64" bx=%"
- PRIx64" cx=%"PRIx64" dx=%"PRIx64" si=%"PRIx64" di=%"
- PRIx64"\n",
- regs->rip, cmd, regs->rax, regs->rbx, regs->rcx,
- regs->rdx, regs->rsi, regs->rdi);
+
if ( dir == IOREQ_READ )
{
+ HVMTRACE_ND(VMPORT_READ_AFTER, 0, 1/*cycles*/, 6,
+ regs->rax, regs->rbx, regs->rcx,
+ regs->rdx, regs->rsi, regs->rdi);
switch ( bytes )
{
case 1:
@@ -171,17 +173,21 @@ int vmport_ioport(int dir, uint32_t port, uint32_t bytes,
uint32_t *val)
*val = regs->rax;
}
else
+ {
+ HVMTRACE_ND(VMPORT_WRITE_AFTER, 0, 1/*cycles*/, 6,
+ regs->rax, regs->rbx, regs->rcx,
+ regs->rdx, regs->rsi, regs->rdi);
regs->rax = saved_rax;
+ }
}
else
{
+ if ( hvm_long_mode_enabled(current) )
+ HVMTRACE_LONG_C4D(VMPORT_BAD, dir, bytes, regs->rax,
+ TRC_PAR_LONG(regs->rip));
+ else
+ HVMTRACE_C4D(VMPORT_BAD, dir, bytes, regs->rax, regs->rip);
rc = X86EMUL_UNHANDLEABLE;
- VMPORT_DBG_LOG(VMPORT_LOG_ERROR,
- "Not VMware %x vs %x; ip=%"PRIx64" ax=%"PRIx64
- " bx=%"PRIx64" cx=%"PRIx64" dx=%"PRIx64" si=%"PRIx64
- " di=%"PRIx64"",
- magic, BDOOR_MAGIC, regs->rip, regs->rax, regs->rbx,
- regs->rcx, regs->rdx, regs->rsi, regs->rdi);
}
return rc;
diff --git a/xen/arch/x86/hvm/vmx/vmx.c b/xen/arch/x86/hvm/vmx/vmx.c
index 73f55f2..5395028 100644
--- a/xen/arch/x86/hvm/vmx/vmx.c
+++ b/xen/arch/x86/hvm/vmx/vmx.c
@@ -2613,6 +2613,12 @@ static void vmx_vmexit_gp_intercept(struct cpu_user_regs
*regs,
__vmread(VM_EXIT_INSTRUCTION_LEN, &inst_len);
__vmread(VM_EXIT_INTR_ERROR_CODE, &ecode);
+ if ( hvm_long_mode_enabled(v) )
+ HVMTRACE_LONG2_C4D(TRAP_GP, inst_len, regs->rdx, TRC_PAR_LONG(ecode),
+ TRC_PAR_LONG(exit_qualification));
+ else
+ HVMTRACE_C4D(TRAP_GP, inst_len, regs->rdx, ecode, exit_qualification);
Do you think anyone will need this 2 years from now? That is, will this
actually be useful in understanding guest behavior, or is this mostly to
help you debug the hypervisor as you're developing it?
I'd like to say more about my general theory for traces, but my brain
has about shut down... I'll send this so you can have the comments I've
got so far, and I'll come back to it tomorrow.
Just one more thing...
+
#ifndef NDEBUG
orig_inst_len = inst_len;
#endif
@@ -2636,6 +2642,12 @@ static void vmx_vmexit_gp_intercept(struct cpu_user_regs
*regs,
regs->rip, inst_addr, orig_inst_len, inst_len,
regs->rax, regs->rbx, regs->rcx, regs->rdx, regs->rsi,
regs->rdi);
+ if ( hvm_long_mode_enabled(v) )
+ HVMTRACE_LONG_C5D(TRAP_GP_UNKNOWN, rc, regs->rax, regs->rbx,
regs->rcx,
+ TRC_PAR_LONG(inst_addr));
+ else
+ HVMTRACE_C5D(TRAP_GP_UNKNOWN, rc, regs->rax, regs->rbx, regs->rcx,
+ inst_addr);
hvm_inject_hw_exception(TRAP_gp_fault, ecode);
}
}
diff --git a/xen/include/asm-x86/hvm/trace.h b/xen/include/asm-x86/hvm/trace.h
index de802a6..8af2d6a 100644
--- a/xen/include/asm-x86/hvm/trace.h
+++ b/xen/include/asm-x86/hvm/trace.h
@@ -52,8 +52,20 @@
#define DO_TRC_HVM_LMSW64 DEFAULT_HVM_MISC
#define DO_TRC_HVM_REALMODE_EMULATE DEFAULT_HVM_MISC
#define DO_TRC_HVM_TRAP DEFAULT_HVM_MISC
+#define DO_TRC_HVM_TRAP64 DEFAULT_HVM_MISC
#define DO_TRC_HVM_TRAP_DEBUG DEFAULT_HVM_MISC
#define DO_TRC_HVM_VLAPIC DEFAULT_HVM_MISC
+#define DO_TRC_HVM_TRAP_GP DEFAULT_HVM_MISC
+#define DO_TRC_HVM_TRAP_GP64 DEFAULT_HVM_MISC
+#define DO_TRC_HVM_TRAP_GP_UNKNOWN DEFAULT_HVM_MISC
+#define DO_TRC_HVM_TRAP_GP_UNKNOWN64 DEFAULT_HVM_MISC
+#define DO_TRC_HVM_VMPORT_READ_BEFORE DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_WRITE_AFTER_BEFORE DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_READ_AFTER DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_WRITE_AFTER DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_BAD DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_BAD64 DEFAULT_HVM_IO
+#define DO_TRC_HVM_VMPORT_UNKNOWN DEFAULT_HVM_IO
#define TRC_PAR_LONG(par) ((par)&0xFFFFFFFF),((par)>>32)
@@ -98,6 +110,21 @@
#define HVMTRACE_0D(evt) \
HVMTRACE_ND(evt, 0, 0, 0, 0, 0, 0, 0, 0, 0)
+#define HVMTRACE_C6D(evt, d1, d2, d3, d4, d5, d6) \
+ HVMTRACE_ND(evt, 0, 1, 6, d1, d2, d3, d4, d5, d6)
+#define HVMTRACE_C5D(evt, d1, d2, d3, d4, d5) \
+ HVMTRACE_ND(evt, 0, 1, 5, d1, d2, d3, d4, d5, 0)
+#define HVMTRACE_C4D(evt, d1, d2, d3, d4) \
+ HVMTRACE_ND(evt, 0, 1, 4, d1, d2, d3, d4, 0, 0)
+#define HVMTRACE_C3D(evt, d1, d2, d3) \
+ HVMTRACE_ND(evt, 0, 1, 3, d1, d2, d3, 0, 0, 0)
+#define HVMTRACE_C2D(evt, d1, d2) \
+ HVMTRACE_ND(evt, 0, 1, 2, d1, d2, 0, 0, 0, 0)
+#define HVMTRACE_C1D(evt, d1) \
+ HVMTRACE_ND(evt, 0, 1, 1, d1, 0, 0, 0, 0, 0)
+#define HVMTRACE_C0D(evt) \
+ HVMTRACE_ND(evt, 0, 1, 0, 0, 0, 0, 0, 0, 0)
+
#define HVMTRACE_LONG_1D(evt, d1) \
HVMTRACE_2D(evt ## 64, (d1) & 0xFFFFFFFF, (d1) >> 32)
#define HVMTRACE_LONG_2D(evt, d1, d2, ...) \
@@ -107,6 +134,24 @@
#define HVMTRACE_LONG_4D(evt, d1, d2, d3, d4, ...) \
HVMTRACE_5D(evt ## 64, d1, d2, d3, d4)
+#define HVMTRACE_LONG_C1D(evt, d1) \
+ HVMTRACE_C2D(evt ## 64, (d1) & 0xFFFFFFFF, (d1) >> 32)
+#define HVMTRACE_LONG_C2D(evt, d1, d2, ...) \
+ HVMTRACE_C3D(evt ## 64, d1, d2)
+#define HVMTRACE_LONG_C3D(evt, d1, d2, d3, ...) \
+ HVMTRACE_C4D(evt ## 64, d1, d2, d3)
+#define HVMTRACE_LONG_C4D(evt, d1, d2, d3, d4, ...) \
+ HVMTRACE_C5D(evt ## 64, d1, d2, d3, d4)
+#define HVMTRACE_LONG_C5D(evt, d1, d2, d3, d4, d5, ...) \
+ HVMTRACE_C6D(evt ## 64, d1, d2, d3, d4, d5)
+
+#define HVMTRACE_LONG2_C2D(evt, d1, d2, ...) \
+ HVMTRACE_C4D(evt ## 64, d1, d2)
+#define HVMTRACE_LONG2_C3D(evt, d1, d2, d3, ...) \
+ HVMTRACE_C5D(evt ## 64, d1, d2, d3)
+#define HVMTRACE_LONG2_C4D(evt, d1, d2, d3, d4, ...) \
+ HVMTRACE_C6D(evt ## 64, d1, d2, d3, d4)
+
#endif /* __ASM_X86_HVM_TRACE_H__ */
/*
diff --git a/xen/include/asm-x86/hvm/vmport.h b/xen/include/asm-x86/hvm/vmport.h
index c4f3926..401cbf4 100644
--- a/xen/include/asm-x86/hvm/vmport.h
+++ b/xen/include/asm-x86/hvm/vmport.h
@@ -25,12 +25,6 @@
#define VMPORT_LOG_VGP_UNKNOWN (1 << 3)
#define VMPORT_LOG_REALMODE_GP (1 << 4)
-#define VMPORT_LOG_GP_NOT_VMWARE (1 << 9)
-
-#define VMPORT_LOG_TRACE (1 << 16)
-#define VMPORT_LOG_ERROR (1 << 17)
-#define VMPORT_LOG_VMWARE_AFTER (1 << 18)
-
If you remove the debug statements in earlier patches, remember to
remove these as well.
-George
_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel
|
