[PATCH v2] xen: arm64: more useful logging on bad trap.

[PATCH v2] xen: arm64: more useful logging on bad trap.

[Ian Campbell]

Dump the register state before panicing so we have some clue where the
issue occurred. Also decode the ESR register a bit to save having to
grab a pen and paper.

ESR_EL2 is a 32-bit register, so use SYSREG_READ32 not ..._READ64, as
we already do correctly in the main trap handler.

While here notice that do_trap_serror is never called and remove it.

Signed-off-by: Ian Campbell <ian.campbell@citrix.com>
Reviewed-by: Julien Grall <julien.grall@linaro.org>
Tested-by: Jintack Lim <jintack@cs.columbia.edu>
Cc: jintack@cs.columbia.edu
---
Jintack, since you have a system which is exhibiting SError issues I
wonder if I could prevail on you to give this patch a try on your
system and report on the output. I've only compile tested this myself.

v2: Added blank line after variable declaration
    Split log message into two lines.
    s/code/ESR/ and reformat a little.
---
 xen/arch/arm/arm64/traps.c |   14 ++++++--------
 1 file changed, 6 insertions(+), 8 deletions(-)

diff --git a/xen/arch/arm/arm64/traps.c b/xen/arch/arm/arm64/traps.c
index 1693b5d..31a3ca5 100644
--- a/xen/arch/arm/arm64/traps.c
+++ b/xen/arch/arm/arm64/traps.c
@@ -24,11 +24,6 @@
 
 #include <public/xen.h>
 
-asmlinkage void do_trap_serror(struct cpu_user_regs *regs)
-{
-    panic("Unhandled serror trap");
-}
-
 static const char *handler[]= {
         "Synchronous Abort",
         "IRQ",
@@ -38,11 +33,14 @@ static const char *handler[]= {
 
 asmlinkage void do_bad_mode(struct cpu_user_regs *regs, int reason)
 {
-    uint64_t esr = READ_SYSREG64(ESR_EL2);
-    printk("Bad mode in %s handler detected, code 0x%08"PRIx64"\n",
-           handler[reason], esr);
+    union hsr hsr = { .bits = READ_SYSREG32(ESR_EL2) };
+
+    printk("Bad mode in %s handler detected", handler[reason]);
+    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
+           hsr.bits, hsr.ec, hsr.len, hsr.iss);
 
     local_irq_disable();
+    show_execution_state(regs);
     panic("bad mode");
 }
 
-- 
1.7.10.4

Re: [PATCH v2] xen: arm64: more useful logging on bad trap.

[Andrew Cooper]

On 18/02/15 17:01, Ian Campbell wrote:
> Dump the register state before panicing so we have some clue where the
> issue occurred. Also decode the ESR register a bit to save having to
> grab a pen and paper.
>
> ESR_EL2 is a 32-bit register, so use SYSREG_READ32 not ..._READ64, as
> we already do correctly in the main trap handler.
>
> While here notice that do_trap_serror is never called and remove it.
>
> Signed-off-by: Ian Campbell <ian.campbell@citrix.com>
> Reviewed-by: Julien Grall <julien.grall@linaro.org>
> Tested-by: Jintack Lim <jintack@cs.columbia.edu>
> Cc: jintack@cs.columbia.edu
> ---
> Jintack, since you have a system which is exhibiting SError issues I
> wonder if I could prevail on you to give this patch a try on your
> system and report on the output. I've only compile tested this myself.
>
> v2: Added blank line after variable declaration
>     Split log message into two lines.
>     s/code/ESR/ and reformat a little.
> ---
>  xen/arch/arm/arm64/traps.c |   14 ++++++--------
>  1 file changed, 6 insertions(+), 8 deletions(-)
>
> diff --git a/xen/arch/arm/arm64/traps.c b/xen/arch/arm/arm64/traps.c
> index 1693b5d..31a3ca5 100644
> --- a/xen/arch/arm/arm64/traps.c
> +++ b/xen/arch/arm/arm64/traps.c
> @@ -24,11 +24,6 @@
>  
>  #include <public/xen.h>
>  
> -asmlinkage void do_trap_serror(struct cpu_user_regs *regs)
> -{
> -    panic("Unhandled serror trap");
> -}
> -
>  static const char *handler[]= {
>          "Synchronous Abort",
>          "IRQ",
> @@ -38,11 +33,14 @@ static const char *handler[]= {
>  
>  asmlinkage void do_bad_mode(struct cpu_user_regs *regs, int reason)
>  {
> -    uint64_t esr = READ_SYSREG64(ESR_EL2);
> -    printk("Bad mode in %s handler detected, code 0x%08"PRIx64"\n",
> -           handler[reason], esr);
> +    union hsr hsr = { .bits = READ_SYSREG32(ESR_EL2) };
> +
> +    printk("Bad mode in %s handler detected", handler[reason]);
> +    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
> +           hsr.bits, hsr.ec, hsr.len, hsr.iss);

This would be better as a single printk() call, otherwise a different
cpu issuing a printk() could interleave in the middle of the line.

Also, you appear to have dropped the space between "detected" and "ESR"

~Andrew

Re: [PATCH v2] xen: arm64: more useful logging on bad trap.

[Ian Campbell]

On Wed, 2015-02-18 at 17:26 +0000, Andrew Cooper wrote:
> On 18/02/15 17:01, Ian Campbell wrote:
> > Dump the register state before panicing so we have some clue where the
> > issue occurred. Also decode the ESR register a bit to save having to
> > grab a pen and paper.
> >
> > ESR_EL2 is a 32-bit register, so use SYSREG_READ32 not ..._READ64, as
> > we already do correctly in the main trap handler.
> >
> > While here notice that do_trap_serror is never called and remove it.
> >
> > Signed-off-by: Ian Campbell <ian.campbell@citrix.com>
> > Reviewed-by: Julien Grall <julien.grall@linaro.org>
> > Tested-by: Jintack Lim <jintack@cs.columbia.edu>
> > Cc: jintack@cs.columbia.edu
> > ---
> > Jintack, since you have a system which is exhibiting SError issues I
> > wonder if I could prevail on you to give this patch a try on your
> > system and report on the output. I've only compile tested this myself.
> >
> > v2: Added blank line after variable declaration
> >     Split log message into two lines.
> >     s/code/ESR/ and reformat a little.
> > ---
> >  xen/arch/arm/arm64/traps.c |   14 ++++++--------
> >  1 file changed, 6 insertions(+), 8 deletions(-)
> >
> > diff --git a/xen/arch/arm/arm64/traps.c b/xen/arch/arm/arm64/traps.c
> > index 1693b5d..31a3ca5 100644
> > --- a/xen/arch/arm/arm64/traps.c
> > +++ b/xen/arch/arm/arm64/traps.c
> > @@ -24,11 +24,6 @@
> >  
> >  #include <public/xen.h>
> >  
> > -asmlinkage void do_trap_serror(struct cpu_user_regs *regs)
> > -{
> > -    panic("Unhandled serror trap");
> > -}
> > -
> >  static const char *handler[]= {
> >          "Synchronous Abort",
> >          "IRQ",
> > @@ -38,11 +33,14 @@ static const char *handler[]= {
> >  
> >  asmlinkage void do_bad_mode(struct cpu_user_regs *regs, int reason)
> >  {
> > -    uint64_t esr = READ_SYSREG64(ESR_EL2);
> > -    printk("Bad mode in %s handler detected, code 0x%08"PRIx64"\n",
> > -           handler[reason], esr);
> > +    union hsr hsr = { .bits = READ_SYSREG32(ESR_EL2) };
> > +
> > +    printk("Bad mode in %s handler detected", handler[reason]);
> > +    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
> > +           hsr.bits, hsr.ec, hsr.len, hsr.iss);
> 
> This would be better as a single printk() call, otherwise a different
> cpu issuing a printk() could interleave in the middle of the line.
> 
> Also, you appear to have dropped the space between "detected" and "ESR"

That's because I forgot to add the \n to the end of the first printk
(the intention was to make the log line <80 columns by splitting it into
two lines). Having fixed that I think your first comment then becomes
irrelevant? Or is there some benefit to printk("foo\nbar\n")?

Ian.

Re: [PATCH v2] xen: arm64: more useful logging on bad trap.

[Andrew Cooper]

On 19/02/15 08:45, Ian Campbell wrote:
> On Wed, 2015-02-18 at 17:26 +0000, Andrew Cooper wrote:
>> On 18/02/15 17:01, Ian Campbell wrote:
>>> Dump the register state before panicing so we have some clue where the
>>> issue occurred. Also decode the ESR register a bit to save having to
>>> grab a pen and paper.
>>>
>>> ESR_EL2 is a 32-bit register, so use SYSREG_READ32 not ..._READ64, as
>>> we already do correctly in the main trap handler.
>>>
>>> While here notice that do_trap_serror is never called and remove it.
>>>
>>> Signed-off-by: Ian Campbell <ian.campbell@citrix.com>
>>> Reviewed-by: Julien Grall <julien.grall@linaro.org>
>>> Tested-by: Jintack Lim <jintack@cs.columbia.edu>
>>> Cc: jintack@cs.columbia.edu
>>> ---
>>> Jintack, since you have a system which is exhibiting SError issues I
>>> wonder if I could prevail on you to give this patch a try on your
>>> system and report on the output. I've only compile tested this myself.
>>>
>>> v2: Added blank line after variable declaration
>>>     Split log message into two lines.
>>>     s/code/ESR/ and reformat a little.
>>> ---
>>>  xen/arch/arm/arm64/traps.c |   14 ++++++--------
>>>  1 file changed, 6 insertions(+), 8 deletions(-)
>>>
>>> diff --git a/xen/arch/arm/arm64/traps.c b/xen/arch/arm/arm64/traps.c
>>> index 1693b5d..31a3ca5 100644
>>> --- a/xen/arch/arm/arm64/traps.c
>>> +++ b/xen/arch/arm/arm64/traps.c
>>> @@ -24,11 +24,6 @@
>>>  
>>>  #include <public/xen.h>
>>>  
>>> -asmlinkage void do_trap_serror(struct cpu_user_regs *regs)
>>> -{
>>> -    panic("Unhandled serror trap");
>>> -}
>>> -
>>>  static const char *handler[]= {
>>>          "Synchronous Abort",
>>>          "IRQ",
>>> @@ -38,11 +33,14 @@ static const char *handler[]= {
>>>  
>>>  asmlinkage void do_bad_mode(struct cpu_user_regs *regs, int reason)
>>>  {
>>> -    uint64_t esr = READ_SYSREG64(ESR_EL2);
>>> -    printk("Bad mode in %s handler detected, code 0x%08"PRIx64"\n",
>>> -           handler[reason], esr);
>>> +    union hsr hsr = { .bits = READ_SYSREG32(ESR_EL2) };
>>> +
>>> +    printk("Bad mode in %s handler detected", handler[reason]);
>>> +    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
>>> +           hsr.bits, hsr.ec, hsr.len, hsr.iss);
>> This would be better as a single printk() call, otherwise a different
>> cpu issuing a printk() could interleave in the middle of the line.
>>
>> Also, you appear to have dropped the space between "detected" and "ESR"
> That's because I forgot to add the \n to the end of the first printk
> (the intention was to make the log line <80 columns by splitting it into
> two lines). Having fixed that I think your first comment then becomes
> irrelevant? Or is there some benefit to printk("foo\nbar\n")?

Not completely irrelevant, but certainly far less problematic, and
something I wouldn't worry about.

 ~Andrew

Re: [PATCH v2] xen: arm64: more useful logging on bad trap.

[Ian Campbell]

On Thu, 2015-02-19 at 10:17 +0000, Andrew Cooper wrote:
> On 19/02/15 08:45, Ian Campbell wrote:
> > On Wed, 2015-02-18 at 17:26 +0000, Andrew Cooper wrote:
> >> On 18/02/15 17:01, Ian Campbell wrote:
> >>> Dump the register state before panicing so we have some clue where the
> >>> issue occurred. Also decode the ESR register a bit to save having to
> >>> grab a pen and paper.
> >>>
> >>> ESR_EL2 is a 32-bit register, so use SYSREG_READ32 not ..._READ64, as
> >>> we already do correctly in the main trap handler.
> >>>
> >>> While here notice that do_trap_serror is never called and remove it.
> >>>
> >>> Signed-off-by: Ian Campbell <ian.campbell@citrix.com>
> >>> Reviewed-by: Julien Grall <julien.grall@linaro.org>
> >>> Tested-by: Jintack Lim <jintack@cs.columbia.edu>
> >>> Cc: jintack@cs.columbia.edu
> >>> ---
> >>> Jintack, since you have a system which is exhibiting SError issues I
> >>> wonder if I could prevail on you to give this patch a try on your
> >>> system and report on the output. I've only compile tested this myself.
> >>>
> >>> v2: Added blank line after variable declaration
> >>>     Split log message into two lines.
> >>>     s/code/ESR/ and reformat a little.
> >>> ---
> >>>  xen/arch/arm/arm64/traps.c |   14 ++++++--------
> >>>  1 file changed, 6 insertions(+), 8 deletions(-)
> >>>
> >>> diff --git a/xen/arch/arm/arm64/traps.c b/xen/arch/arm/arm64/traps.c
> >>> index 1693b5d..31a3ca5 100644
> >>> --- a/xen/arch/arm/arm64/traps.c
> >>> +++ b/xen/arch/arm/arm64/traps.c
> >>> @@ -24,11 +24,6 @@
> >>>  
> >>>  #include <public/xen.h>
> >>>  
> >>> -asmlinkage void do_trap_serror(struct cpu_user_regs *regs)
> >>> -{
> >>> -    panic("Unhandled serror trap");
> >>> -}
> >>> -
> >>>  static const char *handler[]= {
> >>>          "Synchronous Abort",
> >>>          "IRQ",
> >>> @@ -38,11 +33,14 @@ static const char *handler[]= {
> >>>  
> >>>  asmlinkage void do_bad_mode(struct cpu_user_regs *regs, int reason)
> >>>  {
> >>> -    uint64_t esr = READ_SYSREG64(ESR_EL2);
> >>> -    printk("Bad mode in %s handler detected, code 0x%08"PRIx64"\n",
> >>> -           handler[reason], esr);
> >>> +    union hsr hsr = { .bits = READ_SYSREG32(ESR_EL2) };
> >>> +
> >>> +    printk("Bad mode in %s handler detected", handler[reason]);
> >>> +    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
> >>> +           hsr.bits, hsr.ec, hsr.len, hsr.iss);
> >> This would be better as a single printk() call, otherwise a different
> >> cpu issuing a printk() could interleave in the middle of the line.
> >>
> >> Also, you appear to have dropped the space between "detected" and "ESR"
> > That's because I forgot to add the \n to the end of the first printk
> > (the intention was to make the log line <80 columns by splitting it into
> > two lines). Having fixed that I think your first comment then becomes
> > irrelevant? Or is there some benefit to printk("foo\nbar\n")?
> 
> Not completely irrelevant, but certainly far less problematic, and
> something I wouldn't worry about.

Thanks, I think I'll just add the \n on commit rather than bothering
people with a v3 (unless there is some other reason to resend).

Ian.

Re: [PATCH v2] xen: arm64: more useful logging on bad trap.

[Ian Campbell]

On Thu, 2015-02-19 at 10:22 +0000, Ian Campbell wrote:
> > >>> +    printk("Bad mode in %s handler detected", handler[reason]);
> > >>> +    printk("ESR=0x%08"PRIx32":  EC=%"PRIx32", IL=%"PRIx32", ISS=%"PRIx32"\n",
> > >>> +           hsr.bits, hsr.ec, hsr.len, hsr.iss);
> > >> This would be better as a single printk() call, otherwise a different
> > >> cpu issuing a printk() could interleave in the middle of the line.
> > >>
> > >> Also, you appear to have dropped the space between "detected" and "ESR"
> > > That's because I forgot to add the \n to the end of the first printk
> > > (the intention was to make the log line <80 columns by splitting it into
> > > two lines). Having fixed that I think your first comment then becomes
> > > irrelevant? Or is there some benefit to printk("foo\nbar\n")?
> > 
> > Not completely irrelevant, but certainly far less problematic, and
> > something I wouldn't worry about.
> 
> Thanks, I think I'll just add the \n on commit

Which I've now done. thanks all.