IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Joshua Kinard]

Booting a recent kernel on an IP27 system with R14K nodeboards causes the PROM
to bail:

ttyS0:
Command Monitor.  Type "exit" to return to the menu.
>> bootp(): console=ttyS0,9600 root=/dev/md0
Setting $netaddr to 192.168.1.x (from server )
Obtaining  from server
9036672+495920 entry: 0xa800000000689300

MMC:
2A 000: *** General Exception on node 0
2A 000: *** EPC: 0xa800000000022178 (0xa800000000022178)
2A 000: *** Press ENTER to continue.
2A 000: POD MSC Unc> why
2A 000:  EPC    : 0xa800000000022178 (0xa800000000022178)
2A 000:  ERREPC : 0xffffffffbfc00ee0 (0xc00000001fc00ee0)
2A 000:  CACERR : 0x00000000d6d7ff21
2A 000:  Status : 0x0000000024407c80
2A 000:  BadVA  : 0x0000000000000000 (0x0)
2A 000:  RA     : 0xa8000000008771cc (0xa8000000008771cc)
2A 000:  SP     : 0xa80000000081be00
2A 000:  A0     : 0x00000000000051a1
2A 000:  Cause  : 0x000000000000c03c (INT:87------ <Float Pt. Exc>)
2A 000:  Reason : 242 (Unexpected General Exception.)
2A 000:  POD mode was called from: 0xc00000001fc027ec (0xc00000001fc027ec)
2A 000: POD MSC Unc>

Address 0xa800000022178 centers around line 85 in 4.1.0-rc4's
arch/mips/cpu-probe.c:

85:         write_32bit_cp1_register(CP1_STATUS, fcsr0);
    a80000000002216c:       3c020003        lui     v0,0x3
    a800000000022170:       3445ffff        ori     a1,v0,0xffff
    a800000000022174:       00851024        and     v0,a0,a1
--> a800000000022178:       44c2f800        ctc1    v0,$31
    a80000000002217c:       00000000        nop

Looks like cpu_set_fpu_fcsr_mask() was added in April sometime:

http://git.linux-mips.org/cgit/ralf/linux.git/commit/arch/mips/kernel/cpu-probe.c?id=9b26616c8d9dae53fbac7f7cb2c6dd1308102976

Not sure what else can be gleaned.  Seems this version of the R14K (v1.4)
doesn't like that FCSR mask.  Don't recall the Octane complaining about this,
but I'll try to double-check tomorrow.  It's got a newer rev of R14K silicon.
Might be an errata.

--J

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Maciej W. Rozycki]

On Sat, 30 May 2015, Joshua Kinard wrote:

> MMC:
> 2A 000: *** General Exception on node 0
> 2A 000: *** EPC: 0xa800000000022178 (0xa800000000022178)
> 2A 000: *** Press ENTER to continue.
> 2A 000: POD MSC Unc> why
> 2A 000:  EPC    : 0xa800000000022178 (0xa800000000022178)
> 2A 000:  ERREPC : 0xffffffffbfc00ee0 (0xc00000001fc00ee0)
> 2A 000:  CACERR : 0x00000000d6d7ff21
> 2A 000:  Status : 0x0000000024407c80
> 2A 000:  BadVA  : 0x0000000000000000 (0x0)
> 2A 000:  RA     : 0xa8000000008771cc (0xa8000000008771cc)
> 2A 000:  SP     : 0xa80000000081be00
> 2A 000:  A0     : 0x00000000000051a1
> 2A 000:  Cause  : 0x000000000000c03c (INT:87------ <Float Pt. Exc>)
> 2A 000:  Reason : 242 (Unexpected General Exception.)
> 2A 000:  POD mode was called from: 0xc00000001fc027ec (0xc00000001fc027ec)
> 2A 000: POD MSC Unc>
> 
> Address 0xa800000022178 centers around line 85 in 4.1.0-rc4's
> arch/mips/cpu-probe.c:
> 
> 85:         write_32bit_cp1_register(CP1_STATUS, fcsr0);
>     a80000000002216c:       3c020003        lui     v0,0x3
>     a800000000022170:       3445ffff        ori     a1,v0,0xffff
>     a800000000022174:       00851024        and     v0,a0,a1
> --> a800000000022178:       44c2f800        ctc1    v0,$31
>     a80000000002217c:       00000000        nop
> 
> Looks like cpu_set_fpu_fcsr_mask() was added in April sometime:
> 
> http://git.linux-mips.org/cgit/ralf/linux.git/commit/arch/mips/kernel/cpu-probe.c?id=9b26616c8d9dae53fbac7f7cb2c6dd1308102976

 Thanks for your report and the accurate details!

> Not sure what else can be gleaned.  Seems this version of the R14K (v1.4)
> doesn't like that FCSR mask.  Don't recall the Octane complaining about this,
> but I'll try to double-check tomorrow.  It's got a newer rev of R14K silicon.
> Might be an errata.

 Nope, it looks to me like sloppy firmware leaving IEEE 754 exception 
cause and enable bits set behind in FCSR.  Upon writing them back with the 
same values an FPE exception is triggered as per the semantics of the CTC1 
instruction (we have some issues elsewhere with that, e.g. try writing
~0 to $fsr manually under GDB in a program that uses the FPU and then
resuming execution).  I overlooked this possibility.  So it looks to me 
like we need to mask the enables out here and leave the state of FCSR 
clobbered after r/w mask probing.

 Can you please try this diagnostic patch and report the value of FCSR 
printed ("FCSR is:"), and also tell me if the exception has now gone too?  

 I'll submit the final fix, properly annotated, if your testing confirms 
my diagnosis.

 Thanks,

  Maciej

linux-mips-fcsr-mask-fix.diff
Index: linux-org-test/arch/mips/kernel/cpu-probe.c
===================================================================
--- linux-org-test.orig/arch/mips/kernel/cpu-probe.c	2015-06-01 00:43:32.000000000 +0100
+++ linux-org-test/arch/mips/kernel/cpu-probe.c	2015-06-01 00:52:00.714647000 +0100
@@ -80,6 +80,8 @@ static inline void cpu_set_fpu_fcsr_mask
 	__enable_fpu(FPU_AS_IS);
 
 	fcsr = read_32bit_cp1_register(CP1_STATUS);
+	pr_info("FCSR is: %08lx\n", fcsr);
+	fcsr &= ~mask;
 
 	fcsr0 = fcsr & mask;
 	write_32bit_cp1_register(CP1_STATUS, fcsr0);

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Joshua Kinard]

On 05/31/2015 20:09, Maciej W. Rozycki wrote:
> On Sat, 30 May 2015, Joshua Kinard wrote:
> 
>> MMC:
>> 2A 000: *** General Exception on node 0
>> 2A 000: *** EPC: 0xa800000000022178 (0xa800000000022178)
>> 2A 000: *** Press ENTER to continue.
>> 2A 000: POD MSC Unc> why
>> 2A 000:  EPC    : 0xa800000000022178 (0xa800000000022178)
>> 2A 000:  ERREPC : 0xffffffffbfc00ee0 (0xc00000001fc00ee0)
>> 2A 000:  CACERR : 0x00000000d6d7ff21
>> 2A 000:  Status : 0x0000000024407c80
>> 2A 000:  BadVA  : 0x0000000000000000 (0x0)
>> 2A 000:  RA     : 0xa8000000008771cc (0xa8000000008771cc)
>> 2A 000:  SP     : 0xa80000000081be00
>> 2A 000:  A0     : 0x00000000000051a1
>> 2A 000:  Cause  : 0x000000000000c03c (INT:87------ <Float Pt. Exc>)
>> 2A 000:  Reason : 242 (Unexpected General Exception.)
>> 2A 000:  POD mode was called from: 0xc00000001fc027ec (0xc00000001fc027ec)
>> 2A 000: POD MSC Unc>
>>
>> Address 0xa800000022178 centers around line 85 in 4.1.0-rc4's
>> arch/mips/cpu-probe.c:
>>
>> 85:         write_32bit_cp1_register(CP1_STATUS, fcsr0);
>>     a80000000002216c:       3c020003        lui     v0,0x3
>>     a800000000022170:       3445ffff        ori     a1,v0,0xffff
>>     a800000000022174:       00851024        and     v0,a0,a1
>> --> a800000000022178:       44c2f800        ctc1    v0,$31
>>     a80000000002217c:       00000000        nop
>>
>> Looks like cpu_set_fpu_fcsr_mask() was added in April sometime:
>>
>> http://git.linux-mips.org/cgit/ralf/linux.git/commit/arch/mips/kernel/cpu-probe.c?id=9b26616c8d9dae53fbac7f7cb2c6dd1308102976
> 
>  Thanks for your report and the accurate details!
> 
>> Not sure what else can be gleaned.  Seems this version of the R14K (v1.4)
>> doesn't like that FCSR mask.  Don't recall the Octane complaining about this,
>> but I'll try to double-check tomorrow.  It's got a newer rev of R14K silicon.
>> Might be an errata.
> 
>  Nope, it looks to me like sloppy firmware leaving IEEE 754 exception 
> cause and enable bits set behind in FCSR.  Upon writing them back with the 
> same values an FPE exception is triggered as per the semantics of the CTC1 
> instruction (we have some issues elsewhere with that, e.g. try writing
> ~0 to $fsr manually under GDB in a program that uses the FPU and then
> resuming execution).  I overlooked this possibility.  So it looks to me 
> like we need to mask the enables out here and leave the state of FCSR 
> clobbered after r/w mask probing.

ARCS, sloppy?  Never!


>  Can you please try this diagnostic patch and report the value of FCSR 
> printed ("FCSR is:"), and also tell me if the exception has now gone too?  
> 
>  I'll submit the final fix, properly annotated, if your testing confirms 
> my diagnosis.

That got it to boot again.  I added CPU ID to the printk as well, and got some
odd output from one of the CPUs:

# dmesg | grep FCSR
[    0.000000] CPU0: FCSR is: 00000000
[    0.319158] CPU1: FCSR is: 00000000
[    0.364971] CPU2: FCSR is: ffffffffa8000000
[    0.404854] CPU3: FCSR is: 00000000

--J

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Maciej W. Rozycki]

On Sun, 31 May 2015, Joshua Kinard wrote:

> >  Can you please try this diagnostic patch and report the value of FCSR 
> > printed ("FCSR is:"), and also tell me if the exception has now gone too?  
> > 
> >  I'll submit the final fix, properly annotated, if your testing confirms 
> > my diagnosis.
> 
> That got it to boot again.  I added CPU ID to the printk as well, and got some
> odd output from one of the CPUs:
> 
> # dmesg | grep FCSR
> [    0.000000] CPU0: FCSR is: 00000000
> [    0.319158] CPU1: FCSR is: 00000000
> [    0.364971] CPU2: FCSR is: ffffffffa8000000
> [    0.404854] CPU3: FCSR is: 00000000

 The value reported for CPU2 merely shows FCC[7,5,3] bits set, nothing 
really odd about that, the CPU may well have come out of reset like this.  
Neither of the values reported though actually corresponds to the symptom 
you saw, can you double-check you didn't make a typo in your modification 
to `printk'?

 Thanks,

  Maciej

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Ralf Baechle]

On Mon, Jun 01, 2015 at 12:27:52PM +0100, Maciej W. Rozycki wrote:

> > >  Can you please try this diagnostic patch and report the value of FCSR 
> > > printed ("FCSR is:"), and also tell me if the exception has now gone too?  
> > > 
> > >  I'll submit the final fix, properly annotated, if your testing confirms 
> > > my diagnosis.
> > 
> > That got it to boot again.  I added CPU ID to the printk as well, and got some
> > odd output from one of the CPUs:
> > 
> > # dmesg | grep FCSR
> > [    0.000000] CPU0: FCSR is: 00000000
> > [    0.319158] CPU1: FCSR is: 00000000
> > [    0.364971] CPU2: FCSR is: ffffffffa8000000
> > [    0.404854] CPU3: FCSR is: 00000000
> 
>  The value reported for CPU2 merely shows FCC[7,5,3] bits set, nothing 
> really odd about that, the CPU may well have come out of reset like this.  
> Neither of the values reported though actually corresponds to the symptom 
> you saw, can you double-check you didn't make a typo in your modification 
> to `printk'?

Maciej, I don't see why the code is so careful about not trampeling
over any bits that may be set on bootup.  I think we should rather fully
initialize all the exception bits to zero to have the FPU in a known good
state.

  Ralf

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Joshua Kinard]

On 06/01/2015 07:27, Maciej W. Rozycki wrote:
> On Sun, 31 May 2015, Joshua Kinard wrote:
> 
>>>  Can you please try this diagnostic patch and report the value of FCSR 
>>> printed ("FCSR is:"), and also tell me if the exception has now gone too?  
>>>
>>>  I'll submit the final fix, properly annotated, if your testing confirms 
>>> my diagnosis.
>>
>> That got it to boot again.  I added CPU ID to the printk as well, and got some
>> odd output from one of the CPUs:
>>
>> # dmesg | grep FCSR
>> [    0.000000] CPU0: FCSR is: 00000000
>> [    0.319158] CPU1: FCSR is: 00000000
>> [    0.364971] CPU2: FCSR is: ffffffffa8000000
>> [    0.404854] CPU3: FCSR is: 00000000
> 
>  The value reported for CPU2 merely shows FCC[7,5,3] bits set, nothing 
> really odd about that, the CPU may well have come out of reset like this.  
> Neither of the values reported though actually corresponds to the symptom 
> you saw, can you double-check you didn't make a typo in your modification 
> to `printk'?

I commented on it being odd because out of four CPUs, #2 was coming up with a
sign-extended value, twice (I tested two reboot cycles, same both times).  I'm
not fully knowledgable of IP27 hardware, and am probably one of the few on the
planet in possession of R14K node boards, so this might be a quirk of these
specific nodes.  Would need others to test to verify, I guess.

Could always turn on heavy diags and poke through the verbose MSC reporting if
needed.

As for a typo, nope:

	__enable_fpu(FPU_AS_IS);

	fcsr = read_32bit_cp1_register(CP1_STATUS);
->	pr_info("CPU%d: FCSR is: %08lx\n", smp_processor_id(), fcsr);
	fcsr &= ~mask;


--J

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Ralf Baechle]

On Tue, Jun 02, 2015 at 12:56:44AM -0400, Joshua Kinard wrote:

> >>>  I'll submit the final fix, properly annotated, if your testing confirms 
> >>> my diagnosis.
> >>
> >> That got it to boot again.  I added CPU ID to the printk as well, and got some
> >> odd output from one of the CPUs:
> >>
> >> # dmesg | grep FCSR
> >> [    0.000000] CPU0: FCSR is: 00000000
> >> [    0.319158] CPU1: FCSR is: 00000000
> >> [    0.364971] CPU2: FCSR is: ffffffffa8000000
> >> [    0.404854] CPU3: FCSR is: 00000000
> > 
> >  The value reported for CPU2 merely shows FCC[7,5,3] bits set, nothing 
> > really odd about that, the CPU may well have come out of reset like this.  
> > Neither of the values reported though actually corresponds to the symptom 
> > you saw, can you double-check you didn't make a typo in your modification 
> > to `printk'?
> 
> I commented on it being odd because out of four CPUs, #2 was coming up with a
> sign-extended value, twice (I tested two reboot cycles, same both times).  I'm
> not fully knowledgable of IP27 hardware, and am probably one of the few on the
> planet in possession of R14K node boards, so this might be a quirk of these
> specific nodes.  Would need others to test to verify, I guess.
> 
> Could always turn on heavy diags and poke through the verbose MSC reporting if
> needed.
> 
> As for a typo, nope:
> 
> 	__enable_fpu(FPU_AS_IS);
> 
> 	fcsr = read_32bit_cp1_register(CP1_STATUS);
> ->	pr_info("CPU%d: FCSR is: %08lx\n", smp_processor_id(), fcsr);
> 	fcsr &= ~mask;

Maciej, I think the variables sr, mask, fcsr, fcsr0 and fcsr1 should
become unsigned ints; they all represent 32 bit CPU registers.  Also
read_32bit_cp1_register() return a signed int.  A signed int probably
would make more sense here.

  Ralf

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Maciej W. Rozycki]

On Tue, 2 Jun 2015, Joshua Kinard wrote:

> I commented on it being odd because out of four CPUs, #2 was coming up with a
> sign-extended value, twice (I tested two reboot cycles, same both times).  I'm
> not fully knowledgable of IP27 hardware, and am probably one of the few on the
> planet in possession of R14K node boards, so this might be a quirk of these
> specific nodes.  Would need others to test to verify, I guess.

 That's how the CFC1 instruction works, it sign-extends the 32-bit value 
written to the destination register on 64-bit processors.  So if the chip 
has come out of reset with FCSR.FCC[7] set, then the bit will be repeated 
across bits 63:32 when the bit pattern from FCSR has been transferred to a 
general-purpose register.

> As for a typo, nope:
> 
> 	__enable_fpu(FPU_AS_IS);
> 
> 	fcsr = read_32bit_cp1_register(CP1_STATUS);
> ->	pr_info("CPU%d: FCSR is: %08lx\n", smp_processor_id(), fcsr);
> 	fcsr &= ~mask;

 OK, thanks for confirming.  So it looks like the cause of the exception 
vanished at the same time.  There's no harm in reinitialising FCSR here 
though, any vendor-specific bits possibly set will be cleared on process 
creation anyway.

  Maciej

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Maciej W. Rozycki]

On Tue, 2 Jun 2015, Ralf Baechle wrote:

> Maciej, I think the variables sr, mask, fcsr, fcsr0 and fcsr1 should
> become unsigned ints; they all represent 32 bit CPU registers.  Also
> read_32bit_cp1_register() return a signed int.  A signed int probably
> would make more sense here.

 The choice of types for `sr', `fcsr', etc. is I think mainly cosmetic, I 
considered it while implementing `cpu_set_fpu_fcsr_mask', but decided to 
follow prior art for consistency.  Cleaning up the whole of cpu-probe.c 
WRT these types seems reasonable to me.

 Again I think `read_32bit_cp1_register' returns a signed int for 
consistency with `__read_32bit_c0_register' that does too.  Perhaps an 
unsigned int would do for `read_32bit_cp1_register' and then two variants 
of `__read_32bit_c0_register', signed and unsigned, used on a case by case 
basis.

  Maciej

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Joshua Kinard]

On 06/02/2015 07:32, Maciej W. Rozycki wrote:
> On Tue, 2 Jun 2015, Joshua Kinard wrote:
> 
>> I commented on it being odd because out of four CPUs, #2 was coming up with a
>> sign-extended value, twice (I tested two reboot cycles, same both times).  I'm
>> not fully knowledgable of IP27 hardware, and am probably one of the few on the
>> planet in possession of R14K node boards, so this might be a quirk of these
>> specific nodes.  Would need others to test to verify, I guess.
> 
>  That's how the CFC1 instruction works, it sign-extends the 32-bit value 
> written to the destination register on 64-bit processors.  So if the chip 
> has come out of reset with FCSR.FCC[7] set, then the bit will be repeated 
> across bits 63:32 when the bit pattern from FCSR has been transferred to a 
> general-purpose register.
> 
>> As for a typo, nope:
>>
>> 	__enable_fpu(FPU_AS_IS);
>>
>> 	fcsr = read_32bit_cp1_register(CP1_STATUS);
>> ->	pr_info("CPU%d: FCSR is: %08lx\n", smp_processor_id(), fcsr);
>> 	fcsr &= ~mask;
> 
>  OK, thanks for confirming.  So it looks like the cause of the exception 
> vanished at the same time.  There's no harm in reinitialising FCSR here 
> though, any vendor-specific bits possibly set will be cleared on process 
> creation anyway.

I had a thought and moved the printk to be near the top of cpu_probe(), since
it was possible the value of fcsr was getting clobbered by earlier code.  sure
enough, I got saner-looking values:

From full power-down:
# dmesg | grep FCSR
[    0.000000] CPU0: FCSR is: 000051a1
[    0.319163] CPU1: FCSR is: d0828324
[    0.364956] CPU2: FCSR is: a8011980
[    0.404819] CPU3: FCSR is: 00000000

Following a warm reboot cycle:
# dmesg | grep FCSR
[    0.000000] CPU0: FCSR is: 00000000
[    0.319248] CPU1: FCSR is: 00000000
[    0.364920] CPU2: FCSR is: 00000000
[    0.404893] CPU3: FCSR is: 00000000

Following a second full power-down:
# dmesg | grep FCSR
[    0.000000] CPU0: FCSR is: c6001100
[    0.318236] CPU1: FCSR is: 908203a4
[    0.364976] CPU2: FCSR is: a9801888
[    0.404828] CPU3: FCSR is: 08000088

With your new patch posted, it boots up just fine.

--J

Re: IP27: R14000: Unexpected General Exception in cpu_set_fpu_fcsr_mask()

[Joshua Kinard]

On 06/02/2015 07:32, Maciej W. Rozycki wrote:
> On Tue, 2 Jun 2015, Joshua Kinard wrote:
> 
>> I commented on it being odd because out of four CPUs, #2 was coming up with a
>> sign-extended value, twice (I tested two reboot cycles, same both times).  I'm
>> not fully knowledgable of IP27 hardware, and am probably one of the few on the
>> planet in possession of R14K node boards, so this might be a quirk of these
>> specific nodes.  Would need others to test to verify, I guess.
> 
>  That's how the CFC1 instruction works, it sign-extends the 32-bit value 
> written to the destination register on 64-bit processors.  So if the chip 
> has come out of reset with FCSR.FCC[7] set, then the bit will be repeated 
> across bits 63:32 when the bit pattern from FCSR has been transferred to a 
> general-purpose register.
> 
>> As for a typo, nope:
>>
>> 	__enable_fpu(FPU_AS_IS);
>>
>> 	fcsr = read_32bit_cp1_register(CP1_STATUS);
>> ->	pr_info("CPU%d: FCSR is: %08lx\n", smp_processor_id(), fcsr);
>> 	fcsr &= ~mask;
> 
>  OK, thanks for confirming.  So it looks like the cause of the exception 
> vanished at the same time.  There's no harm in reinitialising FCSR here 
> though, any vendor-specific bits possibly set will be cleared on process 
> creation anyway.

I had a thought and moved the printk to be near the top of cpu_probe(), since
it was possible the value of fcsr was getting clobbered by earlier code.  sure
enough, I got saner-looking values: