system lockup with 2.6.29 on Cavium/Octeon

system lockup with 2.6.29 on Cavium/Octeon

[Greg Ungerer]

Hi All,

I have a system lockup problem that I have been looking at on a custom
Cavium/Octeon 5010 based design. I am running on linux-2.6.29 with
David Daney's latest round of PCI and ethernet patches (posted here
on this list).

I have tracked the problem back to local_flush_tlb_kernel_range() in
arch/mips/mm/tlb-r4k.c. At the top of this function is:

     void local_flush_tlb_kernel_range(unsigned long start, unsigned 
long end)
     {
         unsigned long flags;
         int size;

         ENTER_CRITICAL(flags);
         size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
         size = (size + 1) >> 1;
         if (size <= current_cpu_data.tlbsize / 2) {

The problem is that typical example values I see passed in for start
and end are:

     start = c000000000006000
     end   = ffffffffc01d8000

Now the vmalloc area starts at 0xc000000000000000 and the kernel code
and data is all at 0xffffffff80000000 and above. I don't know if the
start and end are reasonable values, but I can see some logic as to
where they come from. The code path that leads to this is via
__vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
to see how we end up with values like this.

But the size calculation above with these types of values will result
in still a large number. Larger than the 32bit "int" that is "size".
I see large negative values fall out as size, and so the following
tlbsize check becomes true, and the code spins inside the loop inside
that if statement for a _very_ long time trying to flush tlb entries.

This is of course easily fixed, by making that size "unsigned long".
The patch below trivially does this.

But is this analysis correct?

Regards
Greg




The address range size calculation inside local_flush_tlb_kernel_range()
is being truncated by a too small size variable holder on 64bit systems.
The truncated size can result in an erroneous tlbsize check that means
we sit spinning inside a loop trying to flush a hige number of TLB
entries. This is for all intents and purposes a system hang. Fix by
using an appropriately sized valiable to hold the size.

Signed-off-by: Greg Ungerer <gerg@snapgear.com>

---

--- ORG.linux-2.6.29/arch/mips/mm/tlb-r4k.c.org	2009-05-20 
15:30:28.000000000 +1000
+++ ORG.linux-2.6.29/arch/mips/mm/tlb-r4k.c	2009-05-20 
15:30:56.000000000 +1000
@@ -161,7 +161,7 @@ void local_flush_tlb_range(struct vm_are
  void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
  {
  	unsigned long flags;
-	int size;
+	unsigned long size;

  	ENTER_CRITICAL(flags);
  	size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;


------------------------------------------------------------------------
Greg Ungerer  --  Principal Engineer        EMAIL:     gerg@snapgear.com
SnapGear Group, McAfee                      PHONE:       +61 7 3435 2888
825 Stanley St,                             FAX:         +61 7 3891 3630
Woolloongabba, QLD, 4102, Australia         WEB: http://www.SnapGear.com

Re: system lockup with 2.6.29 on Cavium/Octeon

[Ralf Baechle]

On Wed, May 20, 2009 at 04:12:32PM +1000, Greg Ungerer wrote:

> I have a system lockup problem that I have been looking at on a custom
> Cavium/Octeon 5010 based design. I am running on linux-2.6.29 with
> David Daney's latest round of PCI and ethernet patches (posted here
> on this list).
>
> I have tracked the problem back to local_flush_tlb_kernel_range() in
> arch/mips/mm/tlb-r4k.c. At the top of this function is:
>
>     void local_flush_tlb_kernel_range(unsigned long start, unsigned long 
> end)
>     {
>         unsigned long flags;
>         int size;
>
>         ENTER_CRITICAL(flags);
>         size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
>         size = (size + 1) >> 1;
>         if (size <= current_cpu_data.tlbsize / 2) {
>
> The problem is that typical example values I see passed in for start
> and end are:
>
>     start = c000000000006000
>     end   = ffffffffc01d8000
>
> Now the vmalloc area starts at 0xc000000000000000 and the kernel code
> and data is all at 0xffffffff80000000 and above. I don't know if the
> start and end are reasonable values, but I can see some logic as to
> where they come from. The code path that leads to this is via
> __vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
> to see how we end up with values like this.

Either start or end address is sensible but not the combination - both
addresses should be in the same segment.  Start is in XKSEG, end in CKSEG2
and in between there are vast wastelands of unused address space exabytes
in size.

> But the size calculation above with these types of values will result
> in still a large number. Larger than the 32bit "int" that is "size".
> I see large negative values fall out as size, and so the following
> tlbsize check becomes true, and the code spins inside the loop inside
> that if statement for a _very_ long time trying to flush tlb entries.
>
> This is of course easily fixed, by making that size "unsigned long".
> The patch below trivially does this.
>
> But is this analysis correct?

Yes - but I think we have two issues here.  The one is the calculation
overflowing int for the arguments you're seeing.  The other being that
the arguments simply are looking wrong.

There are a few more instances of the same overflow issue which the patch
below is fixing.

  Ralf


 arch/mips/mm/tlb-r3k.c |    6 ++----
 arch/mips/mm/tlb-r4k.c |    6 ++----
 arch/mips/mm/tlb-r8k.c |    3 +--
 3 files changed, 5 insertions(+), 10 deletions(-)

diff --git a/arch/mips/mm/tlb-r3k.c b/arch/mips/mm/tlb-r3k.c
index f0cf46a..1c0048a 100644
--- a/arch/mips/mm/tlb-r3k.c
+++ b/arch/mips/mm/tlb-r3k.c
@@ -82,8 +82,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
 	int cpu = smp_processor_id();
 
 	if (cpu_context(cpu, mm) != 0) {
-		unsigned long flags;
-		int size;
+		unsigned long size, flags;
 
 #ifdef DEBUG_TLB
 		printk("[tlbrange<%lu,0x%08lx,0x%08lx>]",
@@ -121,8 +120,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
 
 void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
 {
-	unsigned long flags;
-	int size;
+	unsigned long size, flags;
 
 #ifdef DEBUG_TLB
 	printk("[tlbrange<%lu,0x%08lx,0x%08lx>]", start, end);
diff --git a/arch/mips/mm/tlb-r4k.c b/arch/mips/mm/tlb-r4k.c
index 9619f66..892be42 100644
--- a/arch/mips/mm/tlb-r4k.c
+++ b/arch/mips/mm/tlb-r4k.c
@@ -117,8 +117,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
 	int cpu = smp_processor_id();
 
 	if (cpu_context(cpu, mm) != 0) {
-		unsigned long flags;
-		int size;
+		unsigned long size, flags;
 
 		ENTER_CRITICAL(flags);
 		size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
@@ -160,8 +159,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
 
 void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
 {
-	unsigned long flags;
-	int size;
+	unsigned long size, flags;
 
 	ENTER_CRITICAL(flags);
 	size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
diff --git a/arch/mips/mm/tlb-r8k.c b/arch/mips/mm/tlb-r8k.c
index 4f01a3b..4ec95cc 100644
--- a/arch/mips/mm/tlb-r8k.c
+++ b/arch/mips/mm/tlb-r8k.c
@@ -111,8 +111,7 @@ out_restore:
 /* Usable for KV1 addresses only! */
 void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
 {
-	unsigned long flags;
-	int size;
+	unsigned long size, flags;
 
 	size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
 	size = (size + 1) >> 1;

Re: system lockup with 2.6.29 on Cavium/Octeon

[Greg Ungerer]

Hi Ralf,

Ralf Baechle wrote:
> On Wed, May 20, 2009 at 04:12:32PM +1000, Greg Ungerer wrote:
> 
>> I have a system lockup problem that I have been looking at on a custom
>> Cavium/Octeon 5010 based design. I am running on linux-2.6.29 with
>> David Daney's latest round of PCI and ethernet patches (posted here
>> on this list).
>>
>> I have tracked the problem back to local_flush_tlb_kernel_range() in
>> arch/mips/mm/tlb-r4k.c. At the top of this function is:
>>
>>     void local_flush_tlb_kernel_range(unsigned long start, unsigned long 
>> end)
>>     {
>>         unsigned long flags;
>>         int size;
>>
>>         ENTER_CRITICAL(flags);
>>         size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
>>         size = (size + 1) >> 1;
>>         if (size <= current_cpu_data.tlbsize / 2) {
>>
>> The problem is that typical example values I see passed in for start
>> and end are:
>>
>>     start = c000000000006000
>>     end   = ffffffffc01d8000
>>
>> Now the vmalloc area starts at 0xc000000000000000 and the kernel code
>> and data is all at 0xffffffff80000000 and above. I don't know if the
>> start and end are reasonable values, but I can see some logic as to
>> where they come from. The code path that leads to this is via
>> __vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
>> to see how we end up with values like this.
> 
> Either start or end address is sensible but not the combination - both
> addresses should be in the same segment.  Start is in XKSEG, end in CKSEG2
> and in between there are vast wastelands of unused address space exabytes
> in size.

Yes, exactly, that looked odd to me too.

So I tracked it back to see how these both ended up being in there.
It turns out that MODULE_START, as defined in
arch/mips/include/asm/pgtable-64.h, is CKSSEG, so it is
0xffffffffc0000000 in my case. And VMALLOC_START/MAP_BASE is
defined to be 0xc000000000000000.

In module_alloc() there is a call to __get_vm_area() with MODULE_START
as the start address, and this is how the 0xfff... addresses end up in
the vmap_area table. The usual vmalloc() calls use VMALLOC_START and
that is how the 0xc000... addresses get into the vmap_area table.

Interestingly the definition of MODULE_START is like this:

#if defined(CONFIG_MODULES) && defined(KBUILD_64BIT_SYM32) && \
         VMALLOC_START != CKSSEG
/* Load modules into 32bit-compatible segment. */
#define MODULE_START    CKSSEG


If MODULE_START wasn't defined then the module_alloc() code would
have just called vmalloc() directly - and we wouldn't be in this
mess :-)


>> But the size calculation above with these types of values will result
>> in still a large number. Larger than the 32bit "int" that is "size".
>> I see large negative values fall out as size, and so the following
>> tlbsize check becomes true, and the code spins inside the loop inside
>> that if statement for a _very_ long time trying to flush tlb entries.
>>
>> This is of course easily fixed, by making that size "unsigned long".
>> The patch below trivially does this.
>>
>> But is this analysis correct?
> 
> Yes - but I think we have two issues here.  The one is the calculation
> overflowing int for the arguments you're seeing.  The other being that
> the arguments simply are looking wrong.
> 
> There are a few more instances of the same overflow issue which the patch
> below is fixing.

Indeed, looks good.

Regards
Greg



>   Ralf
> 
> 
>  arch/mips/mm/tlb-r3k.c |    6 ++----
>  arch/mips/mm/tlb-r4k.c |    6 ++----
>  arch/mips/mm/tlb-r8k.c |    3 +--
>  3 files changed, 5 insertions(+), 10 deletions(-)
> 
> diff --git a/arch/mips/mm/tlb-r3k.c b/arch/mips/mm/tlb-r3k.c
> index f0cf46a..1c0048a 100644
> --- a/arch/mips/mm/tlb-r3k.c
> +++ b/arch/mips/mm/tlb-r3k.c
> @@ -82,8 +82,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
>  	int cpu = smp_processor_id();
>  
>  	if (cpu_context(cpu, mm) != 0) {
> -		unsigned long flags;
> -		int size;
> +		unsigned long size, flags;
>  
>  #ifdef DEBUG_TLB
>  		printk("[tlbrange<%lu,0x%08lx,0x%08lx>]",
> @@ -121,8 +120,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
>  
>  void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
>  {
> -	unsigned long flags;
> -	int size;
> +	unsigned long size, flags;
>  
>  #ifdef DEBUG_TLB
>  	printk("[tlbrange<%lu,0x%08lx,0x%08lx>]", start, end);
> diff --git a/arch/mips/mm/tlb-r4k.c b/arch/mips/mm/tlb-r4k.c
> index 9619f66..892be42 100644
> --- a/arch/mips/mm/tlb-r4k.c
> +++ b/arch/mips/mm/tlb-r4k.c
> @@ -117,8 +117,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
>  	int cpu = smp_processor_id();
>  
>  	if (cpu_context(cpu, mm) != 0) {
> -		unsigned long flags;
> -		int size;
> +		unsigned long size, flags;
>  
>  		ENTER_CRITICAL(flags);
>  		size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
> @@ -160,8 +159,7 @@ void local_flush_tlb_range(struct vm_area_struct *vma, unsigned long start,
>  
>  void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
>  {
> -	unsigned long flags;
> -	int size;
> +	unsigned long size, flags;
>  
>  	ENTER_CRITICAL(flags);
>  	size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
> diff --git a/arch/mips/mm/tlb-r8k.c b/arch/mips/mm/tlb-r8k.c
> index 4f01a3b..4ec95cc 100644
> --- a/arch/mips/mm/tlb-r8k.c
> +++ b/arch/mips/mm/tlb-r8k.c
> @@ -111,8 +111,7 @@ out_restore:
>  /* Usable for KV1 addresses only! */
>  void local_flush_tlb_kernel_range(unsigned long start, unsigned long end)
>  {
> -	unsigned long flags;
> -	int size;
> +	unsigned long size, flags;
>  
>  	size = (end - start + (PAGE_SIZE - 1)) >> PAGE_SHIFT;
>  	size = (size + 1) >> 1;
> 

-- 
------------------------------------------------------------------------
Greg Ungerer  --  Principal Engineer        EMAIL:     gerg@snapgear.com
SnapGear Group, McAfee                      PHONE:       +61 7 3435 2888
825 Stanley St,                             FAX:         +61 7 3891 3630
Woolloongabba, QLD, 4102, Australia         WEB: http://www.SnapGear.com

Re: system lockup with 2.6.29 on Cavium/Octeon

[Ralf Baechle]

On Thu, May 21, 2009 at 03:29:05PM +1000, Greg Ungerer wrote:

> Interestingly the definition of MODULE_START is like this:
>
> #if defined(CONFIG_MODULES) && defined(KBUILD_64BIT_SYM32) && \
>         VMALLOC_START != CKSSEG
> /* Load modules into 32bit-compatible segment. */
> #define MODULE_START    CKSSEG
>
>
> If MODULE_START wasn't defined then the module_alloc() code would
> have just called vmalloc() directly - and we wouldn't be in this
> mess :-)

The reason it's done like this is that if the kernel is in CKSEG0 and
modules in CKSEG2 all address references to kernel code and variables are
just 32-bit that is they can be referenced with a much shorter instruction
sequence than for full blown 64-bit code.  This is just one of the
artefacts and I think we can just ignore it.

  Ralf

Re: system lockup with 2.6.29 on Cavium/Octeon

[Atsushi Nemoto]

On Wed, 20 May 2009 15:26:04 +0100, Ralf Baechle <ralf@linux-mips.org> wrote:
> > Now the vmalloc area starts at 0xc000000000000000 and the kernel code
> > and data is all at 0xffffffff80000000 and above. I don't know if the
> > start and end are reasonable values, but I can see some logic as to
> > where they come from. The code path that leads to this is via
> > __vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
> > to see how we end up with values like this.
> 
> Either start or end address is sensible but not the combination - both
> addresses should be in the same segment.  Start is in XKSEG, end in CKSEG2
> and in between there are vast wastelands of unused address space exabytes
> in size.
> 
> > But the size calculation above with these types of values will result
> > in still a large number. Larger than the 32bit "int" that is "size".
> > I see large negative values fall out as size, and so the following
> > tlbsize check becomes true, and the code spins inside the loop inside
> > that if statement for a _very_ long time trying to flush tlb entries.
> >
> > This is of course easily fixed, by making that size "unsigned long".
> > The patch below trivially does this.
> >
> > But is this analysis correct?
> 
> Yes - but I think we have two issues here.  The one is the calculation
> overflowing int for the arguments you're seeing.  The other being that
> the arguments simply are looking wrong.

The wrong combination comes from lazy vunmapping which was introduced
in 2.6.28 cycle.  Maybe we can add new API (non-lazy version of
vfree()) to vmalloc.c to implement module_free(), but I suppose
fallbacking to local_flush_tlb_all() in local_flush_tlb_kernel_range()
is enough().

---
Atsushi Nemoto

Re: system lockup with 2.6.29 on Cavium/Octeon

[Greg Ungerer]

Hi Atsushi,

Atsushi Nemoto wrote:
> On Wed, 20 May 2009 15:26:04 +0100, Ralf Baechle <ralf@linux-mips.org> wrote:
>>> Now the vmalloc area starts at 0xc000000000000000 and the kernel code
>>> and data is all at 0xffffffff80000000 and above. I don't know if the
>>> start and end are reasonable values, but I can see some logic as to
>>> where they come from. The code path that leads to this is via
>>> __vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
>>> to see how we end up with values like this.
>> Either start or end address is sensible but not the combination - both
>> addresses should be in the same segment.  Start is in XKSEG, end in CKSEG2
>> and in between there are vast wastelands of unused address space exabytes
>> in size.
>>
>>> But the size calculation above with these types of values will result
>>> in still a large number. Larger than the 32bit "int" that is "size".
>>> I see large negative values fall out as size, and so the following
>>> tlbsize check becomes true, and the code spins inside the loop inside
>>> that if statement for a _very_ long time trying to flush tlb entries.
>>>
>>> This is of course easily fixed, by making that size "unsigned long".
>>> The patch below trivially does this.
>>>
>>> But is this analysis correct?
>> Yes - but I think we have two issues here.  The one is the calculation
>> overflowing int for the arguments you're seeing.  The other being that
>> the arguments simply are looking wrong.
> 
> The wrong combination comes from lazy vunmapping which was introduced
> in 2.6.28 cycle.  Maybe we can add new API (non-lazy version of
> vfree()) to vmalloc.c to implement module_free(), but I suppose
> fallbacking to local_flush_tlb_all() in local_flush_tlb_kernel_range()
> is enough().

Is there any performance impact on falling back to that?

The flushing due to lazy vunmapping didn't seem to happen
often in the tests I was running.

Regards
Greg


------------------------------------------------------------------------
Greg Ungerer  --  Principal Engineer        EMAIL:     gerg@snapgear.com
SnapGear Group, McAfee                      PHONE:       +61 7 3435 2888
825 Stanley St,                             FAX:         +61 7 3891 3630
Woolloongabba, QLD, 4102, Australia         WEB: http://www.SnapGear.com

Re: system lockup with 2.6.29 on Cavium/Octeon

[Ralf Baechle]

On Fri, May 22, 2009 at 11:19:00AM +1000, Greg Ungerer wrote:

> Atsushi Nemoto wrote:
>> On Wed, 20 May 2009 15:26:04 +0100, Ralf Baechle <ralf@linux-mips.org> wrote:
>>>> Now the vmalloc area starts at 0xc000000000000000 and the kernel code
>>>> and data is all at 0xffffffff80000000 and above. I don't know if the
>>>> start and end are reasonable values, but I can see some logic as to
>>>> where they come from. The code path that leads to this is via
>>>> __vunmap() and __purge_vmap_area_lazy(). So it is not too difficult
>>>> to see how we end up with values like this.
>>> Either start or end address is sensible but not the combination - both
>>> addresses should be in the same segment.  Start is in XKSEG, end in CKSEG2
>>> and in between there are vast wastelands of unused address space exabytes
>>> in size.
>>>
>>>> But the size calculation above with these types of values will result
>>>> in still a large number. Larger than the 32bit "int" that is "size".
>>>> I see large negative values fall out as size, and so the following
>>>> tlbsize check becomes true, and the code spins inside the loop inside
>>>> that if statement for a _very_ long time trying to flush tlb entries.
>>>>
>>>> This is of course easily fixed, by making that size "unsigned long".
>>>> The patch below trivially does this.
>>>>
>>>> But is this analysis correct?
>>> Yes - but I think we have two issues here.  The one is the calculation
>>> overflowing int for the arguments you're seeing.  The other being that
>>> the arguments simply are looking wrong.
>>
>> The wrong combination comes from lazy vunmapping which was introduced
>> in 2.6.28 cycle.  Maybe we can add new API (non-lazy version of
>> vfree()) to vmalloc.c to implement module_free(), but I suppose
>> fallbacking to local_flush_tlb_all() in local_flush_tlb_kernel_range()
>> is enough().
>
> Is there any performance impact on falling back to that?
>
> The flushing due to lazy vunmapping didn't seem to happen
> often in the tests I was running.

It would depend on the workload.  Some depend heavily on the performance
of vmalloc & co.  What I'm wondering now is if we no tend to always flush
the entire TLB instead of just a few entries.  The real cost of a TLB
flush is often not the flushing but the eventual reload of the entries.
That's factors that are hard to predict so benchmarking would be
interesting.

  Ralf

Re: system lockup with 2.6.29 on Cavium/Octeon

[Atsushi Nemoto]

On Fri, 22 May 2009 11:19:00 +1000, Greg Ungerer <gerg@snapgear.com> wrote:
> > The wrong combination comes from lazy vunmapping which was introduced
> > in 2.6.28 cycle.  Maybe we can add new API (non-lazy version of
> > vfree()) to vmalloc.c to implement module_free(), but I suppose
> > fallbacking to local_flush_tlb_all() in local_flush_tlb_kernel_range()
> > is enough().
> 
> Is there any performance impact on falling back to that?
> 
> The flushing due to lazy vunmapping didn't seem to happen
> often in the tests I was running.

I think the wrong combination can happen only when some modules were
unloaded, so performance impact would not be serious even if exists.

---
Atsushi Nemoto