diff mbox

[1/2] x86/vmx: dump MSR load area

Message ID 1470812378-4513-1-git-send-email-msw@amzn.com (mailing list archive)
State New, archived
Headers show

Commit Message

Matt Wilson Aug. 10, 2016, 6:59 a.m. UTC 
From: Matt Wilson <msw@amazon.com>

... as it is very helpful to diagnose VM entry failures due to MSR
loading.

Signed-off-by: Matt Wilson <msw@amazon.com>
---
 xen/arch/x86/hvm/vmx/vmcs.c | 21 +++++++++++++++++++++
 1 file changed, 21 insertions(+)

Comments

Jan Beulich Aug. 10, 2016, 10:44 a.m. UTC | #1 
>>> On 10.08.16 at 08:59, <msw@amzn.com> wrote:
> --- a/xen/arch/x86/hvm/vmx/vmcs.c
> +++ b/xen/arch/x86/hvm/vmx/vmcs.c
> @@ -1740,6 +1740,20 @@ static void vmx_dump_sel2(char *name, uint32_t lim)
>      printk("%s:            %08x %016"PRIx64"\n", name, limit, base);
>  }
>  
> +static void vmx_dump_vcpu_msr_area(struct vcpu *v)

const

> +{
> +    const struct vmx_msr_entry *msr_area = v->arch.hvm_vmx.msr_area;
> +    unsigned int i, msr_count = v->arch.hvm_vmx.msr_count;
> +
> +    printk("  msr_count = %d\n", v->arch.hvm_vmx.msr_count);

Please use the local variable you have just latched and %u.

> +    for ( i = 0; i < msr_count; i++ )
> +    {
> +        printk("  msr_area[%d].index=0x%08x .data=0x%016lx\n",

[%u], and I'm not sure the 0x prefixes are really all that helpful
here. I think it would also be beneficial to shorten the logged text
a little, as this may consume quite a bit of serial line bandwidth.
How about "   MSR[%08x]=%016lx\n"?

> @@ -1879,6 +1893,13 @@ void vmcs_dump_vcpu(struct vcpu *v)
>           (SECONDARY_EXEC_ENABLE_VPID | SECONDARY_EXEC_ENABLE_VM_FUNCTIONS) 
> )
>          printk("Virtual processor ID = 0x%04x VMfunc controls = %016lx\n",
>                 vmr16(VIRTUAL_PROCESSOR_ID), vmr(VM_FUNCTION_CONTROL));
> +    printk("EXIT MSR load count = 0x%04x\n",
> +           (uint32_t)vmr(VM_EXIT_MSR_LOAD_COUNT));
> +    printk("EXIT MSR store count = 0x%04x\n",
> +           (uint32_t)vmr(VM_EXIT_MSR_STORE_COUNT));
> +    printk("ENTRY MSR load count = 0x%04x\n",
> +           (uint32_t)vmr(VM_ENTRY_MSR_LOAD_COUNT));

First - do you really need to make three log lines out of these? And
then, please use vmr32(), as the neighboring vmr16() suggests.
Plus finally - please log all four counts consistently either in hex
or in dec.

Jan
Matt Wilson Aug. 10, 2016, 2:25 p.m. UTC | #2 
On Wed, Aug 10, 2016 at 04:44:21AM -0600, Jan Beulich wrote:
> >>> On 10.08.16 at 08:59, <msw@amzn.com> wrote:
> > --- a/xen/arch/x86/hvm/vmx/vmcs.c
> > +++ b/xen/arch/x86/hvm/vmx/vmcs.c
> > @@ -1740,6 +1740,20 @@ static void vmx_dump_sel2(char *name, uint32_t lim)
> >      printk("%s:            %08x %016"PRIx64"\n", name, limit, base);
> >  }
> >  
> > +static void vmx_dump_vcpu_msr_area(struct vcpu *v)
> 
> const

Ack.

> > +{
> > +    const struct vmx_msr_entry *msr_area = v->arch.hvm_vmx.msr_area;
> > +    unsigned int i, msr_count = v->arch.hvm_vmx.msr_count;
> > +
> > +    printk("  msr_count = %d\n", v->arch.hvm_vmx.msr_count);
> 
> Please use the local variable you have just latched and %u.

Ack.

> > +    for ( i = 0; i < msr_count; i++ )
> > +    {
> > +        printk("  msr_area[%d].index=0x%08x .data=0x%016lx\n",
> 
> [%u], and I'm not sure the 0x prefixes are really all that helpful
> here. I think it would also be beneficial to shorten the logged text
> a little, as this may consume quite a bit of serial line bandwidth.
> How about "   MSR[%08x]=%016lx\n"?

Everyone isn't running at 115,200 baud these days? ;-)

Ack.

> > @@ -1879,6 +1893,13 @@ void vmcs_dump_vcpu(struct vcpu *v)
> >           (SECONDARY_EXEC_ENABLE_VPID | SECONDARY_EXEC_ENABLE_VM_FUNCTIONS) 
> > )
> >          printk("Virtual processor ID = 0x%04x VMfunc controls = %016lx\n",
> >                 vmr16(VIRTUAL_PROCESSOR_ID), vmr(VM_FUNCTION_CONTROL));
> > +    printk("EXIT MSR load count = 0x%04x\n",
> > +           (uint32_t)vmr(VM_EXIT_MSR_LOAD_COUNT));
> > +    printk("EXIT MSR store count = 0x%04x\n",
> > +           (uint32_t)vmr(VM_EXIT_MSR_STORE_COUNT));
> > +    printk("ENTRY MSR load count = 0x%04x\n",
> > +           (uint32_t)vmr(VM_ENTRY_MSR_LOAD_COUNT));
> 
> First - do you really need to make three log lines out of these? And
> then, please use vmr32(), as the neighboring vmr16() suggests.
> Plus finally - please log all four counts consistently either in hex
> or in dec.

With one line, output might look something like:
(XEN) MSR load/store count ExitLoad=0x0001 ExitStore=0x0023 EntryLoad=0x0023

Spaces around = are inconsistent in the existing output and it seems
that no space is more popular. Does this format seem better to you?

I see three counts here - are you talking about the msr_count above?
For msr_count I was thinking that this is internal Xen state, whereas
the other values are VMCS fields where everything else is dumped in
hex. I think printing msr_count is redundant (one could just count the
lines of output), so I'll just remove it.

--msw
Jan Beulich Aug. 11, 2016, 8:46 a.m. UTC | #3 
>>> On 10.08.16 at 16:25, <msw@amzn.com> wrote:
> On Wed, Aug 10, 2016 at 04:44:21AM -0600, Jan Beulich wrote:
>> >>> On 10.08.16 at 08:59, <msw@amzn.com> wrote:
>> > @@ -1879,6 +1893,13 @@ void vmcs_dump_vcpu(struct vcpu *v)
>> >           (SECONDARY_EXEC_ENABLE_VPID | SECONDARY_EXEC_ENABLE_VM_FUNCTIONS) 
> 
>> > )
>> >          printk("Virtual processor ID = 0x%04x VMfunc controls = %016lx\n",
>> >                 vmr16(VIRTUAL_PROCESSOR_ID), vmr(VM_FUNCTION_CONTROL));
>> > +    printk("EXIT MSR load count = 0x%04x\n",
>> > +           (uint32_t)vmr(VM_EXIT_MSR_LOAD_COUNT));
>> > +    printk("EXIT MSR store count = 0x%04x\n",
>> > +           (uint32_t)vmr(VM_EXIT_MSR_STORE_COUNT));
>> > +    printk("ENTRY MSR load count = 0x%04x\n",
>> > +           (uint32_t)vmr(VM_ENTRY_MSR_LOAD_COUNT));
>> 
>> First - do you really need to make three log lines out of these? And
>> then, please use vmr32(), as the neighboring vmr16() suggests.
>> Plus finally - please log all four counts consistently either in hex
>> or in dec.
> 
> With one line, output might look something like:
> (XEN) MSR load/store count ExitLoad=0x0001 ExitStore=0x0023 EntryLoad=0x0023
> 
> Spaces around = are inconsistent in the existing output and it seems
> that no space is more popular. Does this format seem better to you?

Yes.

> I see three counts here - are you talking about the msr_count above?

Yes.

> For msr_count I was thinking that this is internal Xen state, whereas
> the other values are VMCS fields where everything else is dumped in
> hex. I think printing msr_count is redundant (one could just count the
> lines of output), so I'll just remove it.

That's fine as an option of course.

Jan
diff mbox

Patch

diff --git a/xen/arch/x86/hvm/vmx/vmcs.c b/xen/arch/x86/hvm/vmx/vmcs.c
index 1bd875a..a540d4e 100644
--- a/xen/arch/x86/hvm/vmx/vmcs.c
+++ b/xen/arch/x86/hvm/vmx/vmcs.c
@@ -1740,6 +1740,20 @@  static void vmx_dump_sel2(char *name, uint32_t lim)
     printk("%s:            %08x %016"PRIx64"\n", name, limit, base);
 }
 
+static void vmx_dump_vcpu_msr_area(struct vcpu *v)
+{
+    const struct vmx_msr_entry *msr_area = v->arch.hvm_vmx.msr_area;
+    unsigned int i, msr_count = v->arch.hvm_vmx.msr_count;
+
+    printk("  msr_count = %d\n", v->arch.hvm_vmx.msr_count);
+    for ( i = 0; i < msr_count; i++ )
+    {
+        printk("  msr_area[%d].index=0x%08x .data=0x%016lx\n",
+               i, msr_area[i].index, msr_area[i].data);
+    }
+}
+
+
 void vmcs_dump_vcpu(struct vcpu *v)
 {
     struct cpu_user_regs *regs = &v->arch.user_regs;
@@ -1879,6 +1893,13 @@  void vmcs_dump_vcpu(struct vcpu *v)
          (SECONDARY_EXEC_ENABLE_VPID | SECONDARY_EXEC_ENABLE_VM_FUNCTIONS) )
         printk("Virtual processor ID = 0x%04x VMfunc controls = %016lx\n",
                vmr16(VIRTUAL_PROCESSOR_ID), vmr(VM_FUNCTION_CONTROL));
+    printk("EXIT MSR load count = 0x%04x\n",
+           (uint32_t)vmr(VM_EXIT_MSR_LOAD_COUNT));
+    printk("EXIT MSR store count = 0x%04x\n",
+           (uint32_t)vmr(VM_EXIT_MSR_STORE_COUNT));
+    printk("ENTRY MSR load count = 0x%04x\n",
+           (uint32_t)vmr(VM_ENTRY_MSR_LOAD_COUNT));
+    vmx_dump_vcpu_msr_area(v);
 
     vmx_vmcs_exit(v);
 }