[PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Andrew Cooper]

 * Use gprintk rather than gdprintk.  These logging messages shouldn't
   disappear in release builds, as they usually happen immediately before a
   domain crash.  Raise them from WARNING to ERR.
 * Format the vmexit reason in the same base as is used in the vendor
   manuals (decimal for Intel, hex for AMD), and consistently use 0x for hex
   numbers.

In particular, this corrects the information printed for nested VT-x, and
actually prints information for nested SVM.

Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com>
---
CC: Jan Beulich <JBeulich@suse.com>
CC: Jun Nakajima <jun.nakajima@intel.com>
CC: Kevin Tian <kevin.tian@intel.com>
CC: Boris Ostrovsky <boris.ostrovsky@oracle.com>
CC: Suravee Suthikulpanit <suravee.suthikulpanit@amd.com>
CC: Julien Grall <julien.grall@arm.com>

Request for this to be in 4.9, for the purposes of these log messages
remaining present in release builds.  The nested versions are less important,
but modified here for consistency.

For the nested virt side of things, it is insecure to ever hit the default
case, as it causes unknown exits to be handled in the context of being L1,
even when it originated from L2.  I considered putting using domain_crash(),
but that isn't very helpful, and nested virt is still strictly expermiental.
---
 xen/arch/x86/hvm/svm/nestedsvm.c | 2 ++
 xen/arch/x86/hvm/svm/svm.c       | 7 +++----
 xen/arch/x86/hvm/vmx/vmx.c       | 2 +-
 xen/arch/x86/hvm/vmx/vvmx.c      | 4 ++--
 4 files changed, 8 insertions(+), 7 deletions(-)

diff --git a/xen/arch/x86/hvm/svm/nestedsvm.c b/xen/arch/x86/hvm/svm/nestedsvm.c
index d4fc81f..097a4d8 100644
--- a/xen/arch/x86/hvm/svm/nestedsvm.c
+++ b/xen/arch/x86/hvm/svm/nestedsvm.c
@@ -1406,6 +1406,8 @@ nestedsvm_check_intercepts(struct vcpu *v, struct cpu_user_regs *regs,
         /* Always let the guest handle VMMCALL/VMCALL */
         return NESTEDHVM_VMEXIT_INJECT;
     default:
+        gprintk(XENLOG_ERR, "Unhandled nested vmexit: reason %#"PRIx64"\n",
+                exitcode);
         break;
     }
 
diff --git a/xen/arch/x86/hvm/svm/svm.c b/xen/arch/x86/hvm/svm/svm.c
index 07e9718..68bdcdd 100644
--- a/xen/arch/x86/hvm/svm/svm.c
+++ b/xen/arch/x86/hvm/svm/svm.c
@@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
 
     default:
     unexpected_exit_type:
-        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
-                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
-                 exit_reason, 
-                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
+        gprintk(XENLOG_ERR, "Bad vmexit: reason %#"PRIx64", "
+                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
+                exit_reason, (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
         svm_crash_or_fault(v);
         break;
     }
diff --git a/xen/arch/x86/hvm/vmx/vmx.c b/xen/arch/x86/hvm/vmx/vmx.c
index f8d3c17..98d3f08 100644
--- a/xen/arch/x86/hvm/vmx/vmx.c
+++ b/xen/arch/x86/hvm/vmx/vmx.c
@@ -4106,7 +4106,7 @@ void vmx_vmexit_handler(struct cpu_user_regs *regs)
     /* fall through */
     default:
     exit_and_crash:
-        gdprintk(XENLOG_WARNING, "Bad vmexit (reason %#lx)\n", exit_reason);
+        gprintk(XENLOG_ERR, "Bad vmexit: reason %ld\n", exit_reason);
 
         if ( vmx_get_cpl() )
             hvm_inject_hw_exception(TRAP_invalid_op,
diff --git a/xen/arch/x86/hvm/vmx/vvmx.c b/xen/arch/x86/hvm/vmx/vvmx.c
index 936feb6..560babb 100644
--- a/xen/arch/x86/hvm/vmx/vvmx.c
+++ b/xen/arch/x86/hvm/vmx/vvmx.c
@@ -2550,8 +2550,8 @@ int nvmx_n2_vmexit_handler(struct cpu_user_regs *regs,
             nvcpu->nv_vmexit_pending = 1;
         break;
     default:
-        gdprintk(XENLOG_WARNING, "Unknown nested vmexit reason %x.\n",
-                 exit_reason);
+        gprintk(XENLOG_ERR, "Unhandled nested vmexit: reason %u\n",
+                exit_reason);
     }
 
     return ( nvcpu->nv_vmexit_pending == 1 );
-- 
2.1.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Boris Ostrovsky]

On 04/19/2017 11:58 AM, Andrew Cooper wrote:
>  * Use gprintk rather than gdprintk.  These logging messages shouldn't
>    disappear in release builds, as they usually happen immediately before a
>    domain crash.  Raise them from WARNING to ERR.
>  * Format the vmexit reason in the same base as is used in the vendor
>    manuals (decimal for Intel, hex for AMD), and consistently use 0x for hex
>    numbers.
>
> In particular, this corrects the information printed for nested VT-x, and
> actually prints information for nested SVM.
>
> Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com>

Reviewed-by: Boris Ostrovsky <boris.ostrovsky@oracle.com>



_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Jan Beulich]

 >>> On 19.04.17 at 17:58, <andrew.cooper3@citrix.com> wrote:
> --- a/xen/arch/x86/hvm/svm/svm.c
> +++ b/xen/arch/x86/hvm/svm/svm.c
> @@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
>  
>      default:
>      unexpected_exit_type:
> -        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
> -                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
> -                 exit_reason, 
> -                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %#"PRIx64", "
> +                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
> +                exit_reason, (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);

Personally I think "unexpected" was more appropriate than "bad".
Also I would have wished for you to eliminate the bogus casts as
you touch these lines anyway.

> --- a/xen/arch/x86/hvm/vmx/vmx.c
> +++ b/xen/arch/x86/hvm/vmx/vmx.c
> @@ -4106,7 +4106,7 @@ void vmx_vmexit_handler(struct cpu_user_regs *regs)
>      /* fall through */
>      default:
>      exit_and_crash:
> -        gdprintk(XENLOG_WARNING, "Bad vmexit (reason %#lx)\n", exit_reason);
> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %ld\n", exit_reason);

%lu

With at least this last aspect taken care of
Reviewed-by: Jan Beulich <jbeulich@suse.com>

Jan


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Andrew Cooper]

On 20/04/17 11:52, Jan Beulich wrote:
>  >>> On 19.04.17 at 17:58, <andrew.cooper3@citrix.com> wrote:
>> --- a/xen/arch/x86/hvm/svm/svm.c
>> +++ b/xen/arch/x86/hvm/svm/svm.c
>> @@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
>>  
>>      default:
>>      unexpected_exit_type:
>> -        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
>> -                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
>> -                 exit_reason, 
>> -                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
>> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %#"PRIx64", "
>> +                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
>> +                exit_reason, (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
> Personally I think "unexpected" was more appropriate than "bad".
> Also I would have wished for you to eliminate the bogus casts as
> you touch these lines anyway.

Bad was for consistency between VT-x and SVM, and these messages also
include the exit_and_crash cases, meaning that "unexpected" isn't
entirely appropriate.

I'm happy to take an alternative if you can thing of something better.

>
>> --- a/xen/arch/x86/hvm/vmx/vmx.c
>> +++ b/xen/arch/x86/hvm/vmx/vmx.c
>> @@ -4106,7 +4106,7 @@ void vmx_vmexit_handler(struct cpu_user_regs *regs)
>>      /* fall through */
>>      default:
>>      exit_and_crash:
>> -        gdprintk(XENLOG_WARNING, "Bad vmexit (reason %#lx)\n", exit_reason);
>> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %ld\n", exit_reason);
> %lu
>
> With at least this last aspect taken care of
> Reviewed-by: Jan Beulich <jbeulich@suse.com>

Will fix both.

~Andrew

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Jan Beulich]

>>> On 20.04.17 at 13:01, <andrew.cooper3@citrix.com> wrote:
> On 20/04/17 11:52, Jan Beulich wrote:
>>  >>> On 19.04.17 at 17:58, <andrew.cooper3@citrix.com> wrote:
>>> --- a/xen/arch/x86/hvm/svm/svm.c
>>> +++ b/xen/arch/x86/hvm/svm/svm.c
>>> @@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
>>>  
>>>      default:
>>>      unexpected_exit_type:
>>> -        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
>>> -                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
>>> -                 exit_reason, 
>>> -                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
>>> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %#"PRIx64", "
>>> +                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
>>> +                exit_reason, (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
>> Personally I think "unexpected" was more appropriate than "bad".
>> Also I would have wished for you to eliminate the bogus casts as
>> you touch these lines anyway.
> 
> Bad was for consistency between VT-x and SVM, and these messages also
> include the exit_and_crash cases, meaning that "unexpected" isn't
> entirely appropriate.
> 
> I'm happy to take an alternative if you can thing of something better.

Well - "unexpected"? (Many of the exit_and_crash paths are either
not fitting "bad" any better or are in the same "unexpected" class"
in the VMX case. There's only a single patch coming into SVM's
unexpected_exit_type label, which does seem to fit "unexpected".)

Jan


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Julien Grall]

Hi Andrew,

On 19/04/17 16:58, Andrew Cooper wrote:
>  * Use gprintk rather than gdprintk.  These logging messages shouldn't
>    disappear in release builds, as they usually happen immediately before a
>    domain crash.  Raise them from WARNING to ERR.
>  * Format the vmexit reason in the same base as is used in the vendor
>    manuals (decimal for Intel, hex for AMD), and consistently use 0x for hex
>    numbers.
>
> In particular, this corrects the information printed for nested VT-x, and
> actually prints information for nested SVM.
>
> Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com>
> ---
> CC: Jan Beulich <JBeulich@suse.com>
> CC: Jun Nakajima <jun.nakajima@intel.com>
> CC: Kevin Tian <kevin.tian@intel.com>
> CC: Boris Ostrovsky <boris.ostrovsky@oracle.com>
> CC: Suravee Suthikulpanit <suravee.suthikulpanit@amd.com>
> CC: Julien Grall <julien.grall@arm.com>
>
> Request for this to be in 4.9, for the purposes of these log messages
> remaining present in release builds.  The nested versions are less important,
> but modified here for consistency.

Release-acked-by: Julien Grall <julien.grall@arm.com>

Cheers,

>
> For the nested virt side of things, it is insecure to ever hit the default
> case, as it causes unknown exits to be handled in the context of being L1,
> even when it originated from L2.  I considered putting using domain_crash(),
> but that isn't very helpful, and nested virt is still strictly expermiental.
> ---
>  xen/arch/x86/hvm/svm/nestedsvm.c | 2 ++
>  xen/arch/x86/hvm/svm/svm.c       | 7 +++----
>  xen/arch/x86/hvm/vmx/vmx.c       | 2 +-
>  xen/arch/x86/hvm/vmx/vvmx.c      | 4 ++--
>  4 files changed, 8 insertions(+), 7 deletions(-)
>
> diff --git a/xen/arch/x86/hvm/svm/nestedsvm.c b/xen/arch/x86/hvm/svm/nestedsvm.c
> index d4fc81f..097a4d8 100644
> --- a/xen/arch/x86/hvm/svm/nestedsvm.c
> +++ b/xen/arch/x86/hvm/svm/nestedsvm.c
> @@ -1406,6 +1406,8 @@ nestedsvm_check_intercepts(struct vcpu *v, struct cpu_user_regs *regs,
>          /* Always let the guest handle VMMCALL/VMCALL */
>          return NESTEDHVM_VMEXIT_INJECT;
>      default:
> +        gprintk(XENLOG_ERR, "Unhandled nested vmexit: reason %#"PRIx64"\n",
> +                exitcode);
>          break;
>      }
>
> diff --git a/xen/arch/x86/hvm/svm/svm.c b/xen/arch/x86/hvm/svm/svm.c
> index 07e9718..68bdcdd 100644
> --- a/xen/arch/x86/hvm/svm/svm.c
> +++ b/xen/arch/x86/hvm/svm/svm.c
> @@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
>
>      default:
>      unexpected_exit_type:
> -        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
> -                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
> -                 exit_reason,
> -                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %#"PRIx64", "
> +                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
> +                exit_reason, (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
>          svm_crash_or_fault(v);
>          break;
>      }
> diff --git a/xen/arch/x86/hvm/vmx/vmx.c b/xen/arch/x86/hvm/vmx/vmx.c
> index f8d3c17..98d3f08 100644
> --- a/xen/arch/x86/hvm/vmx/vmx.c
> +++ b/xen/arch/x86/hvm/vmx/vmx.c
> @@ -4106,7 +4106,7 @@ void vmx_vmexit_handler(struct cpu_user_regs *regs)
>      /* fall through */
>      default:
>      exit_and_crash:
> -        gdprintk(XENLOG_WARNING, "Bad vmexit (reason %#lx)\n", exit_reason);
> +        gprintk(XENLOG_ERR, "Bad vmexit: reason %ld\n", exit_reason);
>
>          if ( vmx_get_cpl() )
>              hvm_inject_hw_exception(TRAP_invalid_op,
> diff --git a/xen/arch/x86/hvm/vmx/vvmx.c b/xen/arch/x86/hvm/vmx/vvmx.c
> index 936feb6..560babb 100644
> --- a/xen/arch/x86/hvm/vmx/vvmx.c
> +++ b/xen/arch/x86/hvm/vmx/vvmx.c
> @@ -2550,8 +2550,8 @@ int nvmx_n2_vmexit_handler(struct cpu_user_regs *regs,
>              nvcpu->nv_vmexit_pending = 1;
>          break;
>      default:
> -        gdprintk(XENLOG_WARNING, "Unknown nested vmexit reason %x.\n",
> -                 exit_reason);
> +        gprintk(XENLOG_ERR, "Unhandled nested vmexit: reason %u\n",
> +                exit_reason);
>      }
>
>      return ( nvcpu->nv_vmexit_pending == 1 );
>

-- 
Julien Grall

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

Re: [PATCH] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Tian, Kevin]

> From: Andrew Cooper [mailto:andrew.cooper3@citrix.com]
> Sent: Wednesday, April 19, 2017 11:58 PM
> 
>  * Use gprintk rather than gdprintk.  These logging messages shouldn't
>    disappear in release builds, as they usually happen immediately before a
>    domain crash.  Raise them from WARNING to ERR.
>  * Format the vmexit reason in the same base as is used in the vendor
>    manuals (decimal for Intel, hex for AMD), and consistently use 0x for hex
>    numbers.
> 
> In particular, this corrects the information printed for nested VT-x, and
> actually prints information for nested SVM.
> 
> Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com>

Reviewed-by: Kevin Tian <kevin.tian@intel.com>

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel

[PATCH v2 for-4.9] x86/hvm: Corrections and improvements to unhandled vmexit logging

[Andrew Cooper]

 * Use gprintk rather than gdprintk.  These logging messages shouldn't
   disappear in release builds, as they usually happen immediately before a
   domain crash.  Raise them from WARNING to ERR.
 * Format the vmexit reason in the same base as is used in the vendor
   manuals (decimal for Intel, hex for AMD), and consistently use 0x for hex
   numbers.
 * Consistently use "Unexpected vmexit" terminology.

In particular, this corrects the information printed for nested VT-x, and
actually prints information for nested SVM.

Signed-off-by: Andrew Cooper <andrew.cooper3@citrix.com>
Reviewed-by: Boris Ostrovsky <boris.ostrovsky@oracle.com>
Reviewed-by: Jan Beulich <jbeulich@suse.com>
Reviewed-by: Kevin Tian <kevin.tian@intel.com>
Release-acked-by: Julien Grall <julien.grall@arm.com>
---
v2:
 * Use consistent terminology
 * Remove redundant casts

For the nested virt side of things, it is insecure to ever hit the default
case, as it causes unknown exits to be handled in the context of being L1,
even when it originated from L2.  I considered putting using domain_crash(),
but that isn't very helpful, and nested virt is still strictly expermiental.
---
 xen/arch/x86/hvm/svm/nestedsvm.c | 2 ++
 xen/arch/x86/hvm/svm/svm.c       | 7 +++----
 xen/arch/x86/hvm/vmx/vmx.c       | 2 +-
 xen/arch/x86/hvm/vmx/vvmx.c      | 4 ++--
 4 files changed, 8 insertions(+), 7 deletions(-)

diff --git a/xen/arch/x86/hvm/svm/nestedsvm.c b/xen/arch/x86/hvm/svm/nestedsvm.c
index d4fc81f..f46e346 100644
--- a/xen/arch/x86/hvm/svm/nestedsvm.c
+++ b/xen/arch/x86/hvm/svm/nestedsvm.c
@@ -1406,6 +1406,8 @@ nestedsvm_check_intercepts(struct vcpu *v, struct cpu_user_regs *regs,
         /* Always let the guest handle VMMCALL/VMCALL */
         return NESTEDHVM_VMEXIT_INJECT;
     default:
+        gprintk(XENLOG_ERR, "Unexpected nested vmexit: reason %#"PRIx64"\n",
+                exitcode);
         break;
     }
 
diff --git a/xen/arch/x86/hvm/svm/svm.c b/xen/arch/x86/hvm/svm/svm.c
index 07e9718..178adc5 100644
--- a/xen/arch/x86/hvm/svm/svm.c
+++ b/xen/arch/x86/hvm/svm/svm.c
@@ -2833,10 +2833,9 @@ void svm_vmexit_handler(struct cpu_user_regs *regs)
 
     default:
     unexpected_exit_type:
-        gdprintk(XENLOG_ERR, "unexpected VMEXIT: exit reason = %#"PRIx64", "
-                 "exitinfo1 = %#"PRIx64", exitinfo2 = %#"PRIx64"\n",
-                 exit_reason, 
-                 (u64)vmcb->exitinfo1, (u64)vmcb->exitinfo2);
+        gprintk(XENLOG_ERR, "Unexpected vmexit: reason %#"PRIx64", "
+                "exitinfo1 %#"PRIx64", exitinfo2 %#"PRIx64"\n",
+                exit_reason, vmcb->exitinfo1, vmcb->exitinfo2);
         svm_crash_or_fault(v);
         break;
     }
diff --git a/xen/arch/x86/hvm/vmx/vmx.c b/xen/arch/x86/hvm/vmx/vmx.c
index f8d3c17..c8ef18a 100644
--- a/xen/arch/x86/hvm/vmx/vmx.c
+++ b/xen/arch/x86/hvm/vmx/vmx.c
@@ -4106,7 +4106,7 @@ void vmx_vmexit_handler(struct cpu_user_regs *regs)
     /* fall through */
     default:
     exit_and_crash:
-        gdprintk(XENLOG_WARNING, "Bad vmexit (reason %#lx)\n", exit_reason);
+        gprintk(XENLOG_ERR, "Unexpected vmexit: reason %lu\n", exit_reason);
 
         if ( vmx_get_cpl() )
             hvm_inject_hw_exception(TRAP_invalid_op,
diff --git a/xen/arch/x86/hvm/vmx/vvmx.c b/xen/arch/x86/hvm/vmx/vvmx.c
index 936feb6..3560fae 100644
--- a/xen/arch/x86/hvm/vmx/vvmx.c
+++ b/xen/arch/x86/hvm/vmx/vvmx.c
@@ -2550,8 +2550,8 @@ int nvmx_n2_vmexit_handler(struct cpu_user_regs *regs,
             nvcpu->nv_vmexit_pending = 1;
         break;
     default:
-        gdprintk(XENLOG_WARNING, "Unknown nested vmexit reason %x.\n",
-                 exit_reason);
+        gprintk(XENLOG_ERR, "Unexpected nested vmexit: reason %u\n",
+                exit_reason);
     }
 
     return ( nvcpu->nv_vmexit_pending == 1 );
-- 
2.1.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel