[PATCH] x86/msr: add log messages to MSR state load error paths

[PATCH] x86/msr: add log messages to MSR state load error paths

[Roger Pau Monne]

Some error paths in the MSR state loading logic don't contain error messages,
which makes debugging them quite hard without adding extra patches to print the
information.

Add two new log messages to the MSR state load path that print information
about the entry that failed to load.

No functional change intended.

Signed-off-by: Roger Pau Monné <roger.pau@citrix.com>
---
 xen/arch/x86/hvm/hvm.c | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/xen/arch/x86/hvm/hvm.c b/xen/arch/x86/hvm/hvm.c
index 69a25571db8d..c71087f636c4 100644
--- a/xen/arch/x86/hvm/hvm.c
+++ b/xen/arch/x86/hvm/hvm.c
@@ -1598,10 +1598,19 @@ static int cf_check hvm_load_cpu_msrs(struct domain *d, hvm_domain_context_t *h)
             rc = guest_wrmsr(v, ctxt->msr[i].index, ctxt->msr[i].val);
 
             if ( rc != X86EMUL_OKAY )
+            {
+                printk(XENLOG_G_ERR
+                       "HVM%d.%d load MSR %#x with value %#lx failed: %d\n",
+                       d->domain_id, vcpuid, ctxt->msr[i].index,
+                       ctxt->msr[i].val, rc);
                 return -ENXIO;
+            }
             break;
 
         default:
+            printk(XENLOG_G_ERR
+                   "HVM%d.%d attempted load of unhandled MSR %#x\n",
+                   d->domain_id, vcpuid, ctxt->msr[i].index);
             return -ENXIO;
         }
     }
-- 
2.46.0

Re: [PATCH] x86/msr: add log messages to MSR state load error paths

[Andrew Cooper]

On 07/10/2024 3:03 pm, Roger Pau Monne wrote:
> Some error paths in the MSR state loading logic don't contain error messages,
> which makes debugging them quite hard without adding extra patches to print the
> information.
>
> Add two new log messages to the MSR state load path that print information
> about the entry that failed to load.
>
> No functional change intended.
>
> Signed-off-by: Roger Pau Monné <roger.pau@citrix.com>
> ---
>  xen/arch/x86/hvm/hvm.c | 9 +++++++++

Can we fix the PV side at the same time too?

>  1 file changed, 9 insertions(+)
>
> diff --git a/xen/arch/x86/hvm/hvm.c b/xen/arch/x86/hvm/hvm.c
> index 69a25571db8d..c71087f636c4 100644
> --- a/xen/arch/x86/hvm/hvm.c
> +++ b/xen/arch/x86/hvm/hvm.c
> @@ -1598,10 +1598,19 @@ static int cf_check hvm_load_cpu_msrs(struct domain *d, hvm_domain_context_t *h)
>              rc = guest_wrmsr(v, ctxt->msr[i].index, ctxt->msr[i].val);
>  
>              if ( rc != X86EMUL_OKAY )
> +            {
> +                printk(XENLOG_G_ERR
> +                       "HVM%d.%d load MSR %#x with value %#lx failed: %d\n",
> +                       d->domain_id, vcpuid, ctxt->msr[i].index,
> +                       ctxt->msr[i].val, rc);

Just %pv please.  I don't want to propagate the (occasionally ambiguous)
HVM%d form.

Also, rc may not be great to render.  It's an X86EMUL_*, not an errno.

And saying that, we have a discontinuity between PV and HVM.  PV
translates !OKAY into -EINVAL, whereas HVM translates into -ENXIO.  /sigh

~Andrew

Re: [PATCH] x86/msr: add log messages to MSR state load error paths

[Roger Pau Monné]

On Mon, Oct 07, 2024 at 03:16:47PM +0100, Andrew Cooper wrote:
> On 07/10/2024 3:03 pm, Roger Pau Monne wrote:
> > Some error paths in the MSR state loading logic don't contain error messages,
> > which makes debugging them quite hard without adding extra patches to print the
> > information.
> >
> > Add two new log messages to the MSR state load path that print information
> > about the entry that failed to load.
> >
> > No functional change intended.
> >
> > Signed-off-by: Roger Pau Monné <roger.pau@citrix.com>
> > ---
> >  xen/arch/x86/hvm/hvm.c | 9 +++++++++
> 
> Can we fix the PV side at the same time too?

Sure, I think that would be XEN_DOMCTL_set_vcpu_msrs?

I've noticed that such hypercall doesn't return an error if the MSR is
not handled by Xen (there's no default case returning an error in the
switch that processes the entries to load).

> >  1 file changed, 9 insertions(+)
> >
> > diff --git a/xen/arch/x86/hvm/hvm.c b/xen/arch/x86/hvm/hvm.c
> > index 69a25571db8d..c71087f636c4 100644
> > --- a/xen/arch/x86/hvm/hvm.c
> > +++ b/xen/arch/x86/hvm/hvm.c
> > @@ -1598,10 +1598,19 @@ static int cf_check hvm_load_cpu_msrs(struct domain *d, hvm_domain_context_t *h)
> >              rc = guest_wrmsr(v, ctxt->msr[i].index, ctxt->msr[i].val);
> >  
> >              if ( rc != X86EMUL_OKAY )
> > +            {
> > +                printk(XENLOG_G_ERR
> > +                       "HVM%d.%d load MSR %#x with value %#lx failed: %d\n",
> > +                       d->domain_id, vcpuid, ctxt->msr[i].index,
> > +                       ctxt->msr[i].val, rc);
> 
> Just %pv please.  I don't want to propagate the (occasionally ambiguous)
> HVM%d form.

I also wanted to use %pv here, but it will get out of sync
(style-wise) with the rest of messages of the HVM context loading
logic?  IOW: my preference would be to switch all in one go.

> Also, rc may not be great to render.  It's an X86EMUL_*, not an errno.

Yeah, I know, but at the end it's a message for someone that knows how
to debug the code, so if the error code it's X86EMUL_ based it's at
least bet than not printing it.

> And saying that, we have a discontinuity between PV and HVM.  PV
> translates !OKAY into -EINVAL, whereas HVM translates into -ENXIO.  /sigh

Hm, great, one thing at a time.

Thanks, Roger.

Re: [PATCH] x86/msr: add log messages to MSR state load error paths

[Jan Beulich]

On 07.10.2024 17:32, Roger Pau Monné wrote:
> On Mon, Oct 07, 2024 at 03:16:47PM +0100, Andrew Cooper wrote:
>> On 07/10/2024 3:03 pm, Roger Pau Monne wrote:
>>> Some error paths in the MSR state loading logic don't contain error messages,
>>> which makes debugging them quite hard without adding extra patches to print the
>>> information.
>>>
>>> Add two new log messages to the MSR state load path that print information
>>> about the entry that failed to load.
>>>
>>> No functional change intended.
>>>
>>> Signed-off-by: Roger Pau Monné <roger.pau@citrix.com>
>>> ---
>>>  xen/arch/x86/hvm/hvm.c | 9 +++++++++
>>
>> Can we fix the PV side at the same time too?
> 
> Sure, I think that would be XEN_DOMCTL_set_vcpu_msrs?
> 
> I've noticed that such hypercall doesn't return an error if the MSR is
> not handled by Xen (there's no default case returning an error in the
> switch that processes the entries to load).

I see

                ret = -EINVAL;
                ...
                switch ( msr.index )
                {
                    ...
                    if ( guest_wrmsr(v, msr.index, msr.value) != X86EMUL_OKAY )
                        break;
                    continue;
                }
                break;

which to me means we'll return -EINVAL both when handling an MSR fails (1st
"break") and when encountering an unhandled MSR (2nd "break").

>>> --- a/xen/arch/x86/hvm/hvm.c
>>> +++ b/xen/arch/x86/hvm/hvm.c
>>> @@ -1598,10 +1598,19 @@ static int cf_check hvm_load_cpu_msrs(struct domain *d, hvm_domain_context_t *h)
>>>              rc = guest_wrmsr(v, ctxt->msr[i].index, ctxt->msr[i].val);
>>>  
>>>              if ( rc != X86EMUL_OKAY )
>>> +            {
>>> +                printk(XENLOG_G_ERR
>>> +                       "HVM%d.%d load MSR %#x with value %#lx failed: %d\n",
>>> +                       d->domain_id, vcpuid, ctxt->msr[i].index,
>>> +                       ctxt->msr[i].val, rc);
>>
>> Just %pv please.  I don't want to propagate the (occasionally ambiguous)
>> HVM%d form.
> 
> I also wanted to use %pv here, but it will get out of sync
> (style-wise) with the rest of messages of the HVM context loading
> logic?  IOW: my preference would be to switch all in one go.

I deliberately started using %pv when touching hvm_save() somewhat recently.
So there is some inconsistency right now anyway, and I guess we'll want to
move to the new form as we touch code in this area.

Jan

Re: [PATCH] x86/msr: add log messages to MSR state load error paths

[Roger Pau Monné]

On Tue, Oct 08, 2024 at 08:29:23AM +0200, Jan Beulich wrote:
> On 07.10.2024 17:32, Roger Pau Monné wrote:
> > On Mon, Oct 07, 2024 at 03:16:47PM +0100, Andrew Cooper wrote:
> >> On 07/10/2024 3:03 pm, Roger Pau Monne wrote:
> >>> Some error paths in the MSR state loading logic don't contain error messages,
> >>> which makes debugging them quite hard without adding extra patches to print the
> >>> information.
> >>>
> >>> Add two new log messages to the MSR state load path that print information
> >>> about the entry that failed to load.
> >>>
> >>> No functional change intended.
> >>>
> >>> Signed-off-by: Roger Pau Monné <roger.pau@citrix.com>
> >>> ---
> >>>  xen/arch/x86/hvm/hvm.c | 9 +++++++++
> >>
> >> Can we fix the PV side at the same time too?
> > 
> > Sure, I think that would be XEN_DOMCTL_set_vcpu_msrs?
> > 
> > I've noticed that such hypercall doesn't return an error if the MSR is
> > not handled by Xen (there's no default case returning an error in the
> > switch that processes the entries to load).
> 
> I see
> 
>                 ret = -EINVAL;
>                 ...
>                 switch ( msr.index )
>                 {
>                     ...
>                     if ( guest_wrmsr(v, msr.index, msr.value) != X86EMUL_OKAY )
>                         break;
>                     continue;
>                 }
>                 break;
> 
> which to me means we'll return -EINVAL both when handling an MSR fails (1st
> "break") and when encountering an unhandled MSR (2nd "break").

Oh, I see, I was expecting a construct similar to the one used in
hvm_load_cpu_msrs() and didn't spot that continue.  The logic there is
very obfuscated IMO.

> >>> --- a/xen/arch/x86/hvm/hvm.c
> >>> +++ b/xen/arch/x86/hvm/hvm.c
> >>> @@ -1598,10 +1598,19 @@ static int cf_check hvm_load_cpu_msrs(struct domain *d, hvm_domain_context_t *h)
> >>>              rc = guest_wrmsr(v, ctxt->msr[i].index, ctxt->msr[i].val);
> >>>  
> >>>              if ( rc != X86EMUL_OKAY )
> >>> +            {
> >>> +                printk(XENLOG_G_ERR
> >>> +                       "HVM%d.%d load MSR %#x with value %#lx failed: %d\n",
> >>> +                       d->domain_id, vcpuid, ctxt->msr[i].index,
> >>> +                       ctxt->msr[i].val, rc);
> >>
> >> Just %pv please.  I don't want to propagate the (occasionally ambiguous)
> >> HVM%d form.
> > 
> > I also wanted to use %pv here, but it will get out of sync
> > (style-wise) with the rest of messages of the HVM context loading
> > logic?  IOW: my preference would be to switch all in one go.
> 
> I deliberately started using %pv when touching hvm_save() somewhat recently.
> So there is some inconsistency right now anyway, and I guess we'll want to
> move to the new form as we touch code in this area.

Ack, will adjust to use "HVM %pv" then.

Thanks, Roger.