LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
@ 2004-05-25 22:26 Doug Dumitru
2004-05-25 23:12 ` David S. Miller
0 siblings, 1 reply; 14+ messages in thread
From: Doug Dumitru @ 2004-05-25 22:26 UTC (permalink / raw)
To: linux-kernel, David S. Miller
This is the original trap dump from a __page_alloc error
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
This was the first error that took the machine down entirely (it should
be noted that the machine was >100 LoadAvg soft-hang before this error).
This is with "echo 1 > /proc/sys/vm/vm_gfp_debug" and I ran it thru
ksymoops to try to decode the addresses (I hope I did this right).
ksymoops 2.4.4 on i686 2.4.25. Options used
-V (default)
-k ksyms.5 (specified)
-l /proc/modules (default)
-o /lib/modules/2.4.26/ (specified)
-m /boot/System.map-2.4.26 (specified)
Warning (expand_objects): object
/lib/modules/2.4.26/kernel/drivers/md/lvm-mod.o for module lvm-mod
has changed since load
Warning (expand_objects): object
/lib/modules/2.4.26/kernel/drivers/md/md.o for module md has
changed since load
cc68bad8 c0135289 00000000 011410ac 00000001 0000000c c03689dc 0000
cbccb780 cbccb780 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>]
[<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>]
[<c01f05ec>]
[<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>]
[<c0134271>]
[<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>]
[<c029634f>]
[<c014c467>] [<c014c8e9>] [<c010a72d>] [<c0108b63>]
Warning (Oops_read): Code line not seen, dumping what data is available
Trace; c0135289 <__alloc_pages+2d9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c0132214 <kmem_cache_grow+c4/250>
Trace; c02d23ba <arp_process+48a/4a0>
Trace; c01327f1 <kmalloc+151/180>
Trace; c029923f <alloc_skb+ef/1c0>
Trace; c01f0d3c <e1000_alloc_rx_buffers+dc/110>
Trace; c01f0c52 <e1000_clean_rx_irq+402/410>
Trace; c0121786 <update_wall_time+16/50>
Trace; c01219d9 <timer_bh+39/3f0>
Trace; c01f05ec <e1000_intr+8c/e0>
Trace; c010a4de <handle_IRQ_event+5e/90>
Trace; c010a6f4 <do_IRQ+a4/f0>
Trace; c0133ce6 <shrink_cache+a6/420>
Trace; c0134152 <refill_inactive+f2/160>
Trace; c01341fc <shrink_caches+3c/50>
Trace; c0134271 <try_to_free_pages_zone+61/e0>
Trace; c0134dff <balance_classzone+4f/200>
Trace; c0135169 <__alloc_pages+1b9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c014c203 <__pollwait+33/90>
Trace; c02b765e <tcp_poll+2e/150>
Trace; c029634f <sock_poll+1f/30>
Trace; c014c467 <do_select+127/240>
Trace; c014c8e9 <sys_select+339/480>
Trace; c010a72d <do_IRQ+dd/f0>
Trace; c0108b63 <system_call+33/38>
If I am reading this correctly, the system was ...
in an interrupt
processing some TCP select(...) stuff
asking for a page
doing a zone rebalance
trying to shrink cache
and interrupted again
by the ethernet driver
which wanted to allocate an skb
which wanted a page
Thus __alloc_pages appears to be called recursively, with the 2nd call
during a rebalance in the
first one and both calls non-interuptable (on interrupts). Is this
allowable?
--------------------------------------------------------------------
Doug Dumitru 800-470-2756 (610-237-2000)
EasyCo LLC doug@easyco.com http://easyco.com
--------------------------------------------------------------------
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 22:26 Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory Doug Dumitru
@ 2004-05-25 23:12 ` David S. Miller
2004-05-26 12:59 ` Marcelo Tosatti
0 siblings, 1 reply; 14+ messages in thread
From: David S. Miller @ 2004-05-25 23:12 UTC (permalink / raw)
To: Doug Dumitru; +Cc: linux-kernel
On Tue, 25 May 2004 15:26:30 -0700
Doug Dumitru <doug@easyco.com> wrote:
> This is the original trap dump from a __page_alloc error
>
> __alloc_pages: 0-order allocation failed (gfp=0x20/1)
0x20 means GFP_ATOMIC which means it's fine to fail
and e1000 is doing nothing wrong. GFP_ATOMIC in interrupts
is a fine condition.
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 23:12 ` David S. Miller
@ 2004-05-26 12:59 ` Marcelo Tosatti
2004-05-26 18:59 ` Doug Dumitru
0 siblings, 1 reply; 14+ messages in thread
From: Marcelo Tosatti @ 2004-05-26 12:59 UTC (permalink / raw)
To: David S. Miller; +Cc: Doug Dumitru, linux-kernel
On Tue, May 25, 2004 at 04:12:12PM -0700, David S. Miller wrote:
> On Tue, 25 May 2004 15:26:30 -0700
> Doug Dumitru <doug@easyco.com> wrote:
>
> > This is the original trap dump from a __page_alloc error
> >
> > __alloc_pages: 0-order allocation failed (gfp=0x20/1)
>
> 0x20 means GFP_ATOMIC which means it's fine to fail
> and e1000 is doing nothing wrong. GFP_ATOMIC in interrupts
> is a fine condition.
Yeap, but the crash is not a fine condition... I suspect
what can be happening is extreme gigabit traffic resulting in
memory shortage.
Doug said the load average is really high. Doug, you're not
using NAPI, right? Can you try it?
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-26 12:59 ` Marcelo Tosatti
@ 2004-05-26 18:59 ` Doug Dumitru
0 siblings, 0 replies; 14+ messages in thread
From: Doug Dumitru @ 2004-05-26 18:59 UTC (permalink / raw)
To: Marcelo Tosatti; +Cc: David S. Miller, linux-kernel
Marcelo Tosatti wrote:
> On Tue, May 25, 2004 at 04:12:12PM -0700, David S. Miller wrote:
>
>>On Tue, 25 May 2004 15:26:30 -0700
>>Doug Dumitru <doug@easyco.com> wrote:
>>
>>
>>>This is the original trap dump from a __page_alloc error
>>>
>>>__alloc_pages: 0-order allocation failed (gfp=0x20/1)
>>
>>0x20 means GFP_ATOMIC which means it's fine to fail
>>and e1000 is doing nothing wrong. GFP_ATOMIC in interrupts
>>is a fine condition.
>
>
> Yeap, but the crash is not a fine condition... I suspect
> what can be happening is extreme gigabit traffic resulting in
> memory shortage.
>
> Doug said the load average is really high. Doug, you're not
> using NAPI, right? Can you try it?
Prior to the __page_alloc hang, the loadavg shoots way up, so something
is spinning, but it is hard to tell what. This has persisted for as
long as 8-10 minutes on one hang, although it is usually shorter (1-2
minutes). One of my concerns is that the e1000 issue might only be a
symptom of the page tables getting clobbered by something else. I have
been trying to get the system to hang during more "controlled" usage,
but have been unable to. I have even run tsl (telnet scripting
language) scripts to logon 250 processes and beat the CPU and disk up,
creating and destroying processes along the way. I was able to drive
loadavg > 50 and LowFree to < 5000K, but could never create a hang. I
suspect that I might need truely "random" inbound traffic to find the
bug (but this is a guess).
In terms of network traffic, the system is busy, but not obnoxiously so.
The load on the server is primarily terminal traffic from about 200
"real humans", so there are a lot of small, random packets. In terms of
network bandwidth, it is not all that bad, maybe 2-3 megabits (a guess).
The arp table is reasonably big (> 200 entries) but this is not that
bad either. I have not looked for arp storms or other network anomolies
on the LAN. The system is on a local LAN and gets no internet traffic.
I am unfamiliar with NAPI, so I have not tried it.
On another topic, I am trying to build a 2.4.26 kernel that reserves
more LowFree. The mm/page_alloc.c file describes a boot parameter
called "lower_zone_reserve" that should tune this. Unfortunately, this
parameter seems to be read after the zone tables are initialized (which
is probably a bug).
--
--------------------------------------------------------------------
Doug Dumitru 800-470-2756 (610-237-2000)
EasyCo LLC doug@easyco.com http://easyco.com
--------------------------------------------------------------------
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-26 1:22 (Found?) " Roger Larsson
@ 2004-05-26 19:58 ` Roger Larsson
0 siblings, 0 replies; 14+ messages in thread
From: Roger Larsson @ 2004-05-26 19:58 UTC (permalink / raw)
To: linux-kernel
Modifying the header so you find it. And write a better summary...
* When you have little memory left __alloc_pages wont allow
allocations from interrupt context (even if PF_MEMALLOC)
if (current->flags & PF_MEMALLOC && !in_interrupt()) {
* But in the callchain there is a loop in __kmem_cache_alloc when running SMP
> static inline void * __kmem_cache_alloc (kmem_cache_t *cachep, int flags)
> {
> unsigned long save_flags;
> void* objp;
>
> kmem_cache_alloc_head(cachep, flags);
> try_again:
> local_irq_save(save_flags);
>
> #ifdef CONFIG_SMP
> {
> cpucache_t *cc = cc_data(cachep);
>
> if (cc) {
> if (cc->avail) {
> STATS_INC_ALLOCHIT(cachep);
> objp = cc_entry(cc)[--cc->avail];
> } else {
> STATS_INC_ALLOCMISS(cachep);
> objp = kmem_cache_alloc_batch(cachep,cc,flags);
> if (!objp)
> goto alloc_new_slab_nolock;
>
> - - - snip - - -
> alloc_new_slab_nolock:
> #endif
> local_irq_restore(save_flags);
> if (kmem_cache_grow(cachep, flags))
> /* Someone may have stolen our objs. Doesn't matter, we'll
> * just come back here again.
> */
> goto try_again;
>
> But kmem_cache_grow will return failed...
> -> kmem_getpages -> _get_free_pages -> alloc_pages
But alloc_pages WILL fail every time... => infinite loop in interrupt
context... It probably should not try again in this case...
if (!in_interrupt())
goto try_again;
Or it should check if GFP_WAIT is set... A _busy_ wait is also a wait...
/RogerL
--
Roger Larsson
Skellefteå
Sweden
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 22:53 ` Marcelo Tosatti
@ 2004-05-25 23:39 ` Marcelo Tosatti
0 siblings, 0 replies; 14+ messages in thread
From: Marcelo Tosatti @ 2004-05-25 23:39 UTC (permalink / raw)
To: David S. Miller
Cc: Feldman, Scott, doug, linux-kernel, cramerj, john.ronciak,
ganesh.venkatesan, jgarzik
On Tue, May 25, 2004 at 07:53:09PM -0300, Marcelo Tosatti wrote:
> On Tue, May 25, 2004 at 02:47:59PM -0700, David S. Miller wrote:
> > On Tue, 25 May 2004 14:20:23 -0700
> > "Feldman, Scott" <scott.feldman@intel.com> wrote:
> >
> > > Marcelo Tosatti wrote:
> > >
> > > > It seems we are calling alloc_skb(GFP_KERNEL) from inside an
> > > > interrupt handler. Oops.
> > >
> > > We're calling dev_alloc_skb() from hard interrupt context, but it uses
> > > GFP_ATOMIC, not GFP_KERNEL, so this is OK, right? I don't see the
> > > problem with e1000.
> >
> > Neither do I, where is the detailed backtrace of this GFP_KERNEL
> > allocation supposedly from interrupt context?
>
> That was just a very wrong guess, I must admit.
>
> Actually what seems to be happening is an e1000 IRQ while
> trying to free memory (shrink_caches()) which tries to
> allocate more memory.
>
> Locked caused by extremely high load it seems.
>
> You know better than me.
Probably NAPI makes a difference?
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 21:20 Feldman, Scott
2004-05-25 21:47 ` David S. Miller
@ 2004-05-25 22:53 ` Marcelo Tosatti
1 sibling, 0 replies; 14+ messages in thread
From: Marcelo Tosatti @ 2004-05-25 22:53 UTC (permalink / raw)
To: Feldman, Scott
Cc: Doug Dumitru, linux-kernel, cramerj, Ronciak, John, Venkatesan,
Ganesh, jgarzik
On Tue, May 25, 2004 at 02:20:23PM -0700, Feldman, Scott wrote:
> Marcelo Tosatti wrote:
>
> > It seems we are calling alloc_skb(GFP_KERNEL) from inside an
> > interrupt handler. Oops.
>
> We're calling dev_alloc_skb() from hard interrupt context, but it uses
> GFP_ATOMIC, not GFP_KERNEL, so this is OK, right? I don't see the
> problem with e1000.
Scott,
I'm full of sh*t, just ignore me.
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 21:47 ` David S. Miller
@ 2004-05-25 22:53 ` Marcelo Tosatti
2004-05-25 23:39 ` Marcelo Tosatti
0 siblings, 1 reply; 14+ messages in thread
From: Marcelo Tosatti @ 2004-05-25 22:53 UTC (permalink / raw)
To: David S. Miller
Cc: Feldman, Scott, doug, linux-kernel, cramerj, john.ronciak,
ganesh.venkatesan, jgarzik
On Tue, May 25, 2004 at 02:47:59PM -0700, David S. Miller wrote:
> On Tue, 25 May 2004 14:20:23 -0700
> "Feldman, Scott" <scott.feldman@intel.com> wrote:
>
> > Marcelo Tosatti wrote:
> >
> > > It seems we are calling alloc_skb(GFP_KERNEL) from inside an
> > > interrupt handler. Oops.
> >
> > We're calling dev_alloc_skb() from hard interrupt context, but it uses
> > GFP_ATOMIC, not GFP_KERNEL, so this is OK, right? I don't see the
> > problem with e1000.
>
> Neither do I, where is the detailed backtrace of this GFP_KERNEL
> allocation supposedly from interrupt context?
That was just a very wrong guess, I must admit.
Actually what seems to be happening is an e1000 IRQ while
trying to free memory (shrink_caches()) which tries to
allocate more memory.
Locked caused by extremely high load it seems.
You know better than me.
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
@ 2004-05-25 22:17 Doug Dumitru
0 siblings, 0 replies; 14+ messages in thread
From: Doug Dumitru @ 2004-05-25 22:17 UTC (permalink / raw)
To: linux-kernel, David S. Miller
This is the original trap dump from a __page_alloc error
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
This was the first error that took the machine down entirely (it should
be noted that the machine was >100 LoadAvg soft-hang before this error).
This is with "echo 1 > /proc/sys/vm/vm_gfp_debug" and I ran it thru
ksymoops to try to decode the addresses (I hope I did this right).
ksymoops 2.4.4 on i686 2.4.25. Options used
-V (default)
-k ksyms.5 (specified)
-l /proc/modules (default)
-o /lib/modules/2.4.26/ (specified)
-m /boot/System.map-2.4.26 (specified)
Warning (expand_objects): object
/lib/modules/2.4.26/kernel/drivers/md/lvm-mod.o for module lvm-mod
has changed since load
Warning (expand_objects): object
/lib/modules/2.4.26/kernel/drivers/md/md.o for module md has
changed since load
cc68bad8 c0135289 00000000 011410ac 00000001 0000000c c03689dc 0000
cbccb780 cbccb780 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>]
[<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>]
[<c01f05ec>]
[<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>]
[<c0134271>]
[<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>]
[<c029634f>]
[<c014c467>] [<c014c8e9>] [<c010a72d>] [<c0108b63>]
Warning (Oops_read): Code line not seen, dumping what data is available
Trace; c0135289 <__alloc_pages+2d9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c0132214 <kmem_cache_grow+c4/250>
Trace; c02d23ba <arp_process+48a/4a0>
Trace; c01327f1 <kmalloc+151/180>
Trace; c029923f <alloc_skb+ef/1c0>
Trace; c01f0d3c <e1000_alloc_rx_buffers+dc/110>
Trace; c01f0c52 <e1000_clean_rx_irq+402/410>
Trace; c0121786 <update_wall_time+16/50>
Trace; c01219d9 <timer_bh+39/3f0>
Trace; c01f05ec <e1000_intr+8c/e0>
Trace; c010a4de <handle_IRQ_event+5e/90>
Trace; c010a6f4 <do_IRQ+a4/f0>
Trace; c0133ce6 <shrink_cache+a6/420>
Trace; c0134152 <refill_inactive+f2/160>
Trace; c01341fc <shrink_caches+3c/50>
Trace; c0134271 <try_to_free_pages_zone+61/e0>
Trace; c0134dff <balance_classzone+4f/200>
Trace; c0135169 <__alloc_pages+1b9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c014c203 <__pollwait+33/90>
Trace; c02b765e <tcp_poll+2e/150>
Trace; c029634f <sock_poll+1f/30>
Trace; c014c467 <do_select+127/240>
Trace; c014c8e9 <sys_select+339/480>
Trace; c010a72d <do_IRQ+dd/f0>
Trace; c0108b63 <system_call+33/38>
If I am reading this correctly, the system was ...
in an interrupt
processing some TCP select(...) stuff
asking for a page
doing a zone rebalance
trying to shrink cache
and interrupted again
by the ethernet driver
which wanted to allocate an skb
which wanted a page
Thus __alloc_pages appears to be called recursively, with the 2nd call
during a rebalance in the
first one and both calls non-interuptable (on interrupts). Is this
allowable?
--------------------------------------------------------------------
Doug Dumitru 800-470-2756 (610-237-2000)
EasyCo LLC doug@easyco.com http://easyco.com
--------------------------------------------------------------------
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-25 21:20 Feldman, Scott
@ 2004-05-25 21:47 ` David S. Miller
2004-05-25 22:53 ` Marcelo Tosatti
2004-05-25 22:53 ` Marcelo Tosatti
1 sibling, 1 reply; 14+ messages in thread
From: David S. Miller @ 2004-05-25 21:47 UTC (permalink / raw)
To: Feldman, Scott
Cc: marcelo.tosatti, doug, linux-kernel, cramerj, john.ronciak,
ganesh.venkatesan, jgarzik
On Tue, 25 May 2004 14:20:23 -0700
"Feldman, Scott" <scott.feldman@intel.com> wrote:
> Marcelo Tosatti wrote:
>
> > It seems we are calling alloc_skb(GFP_KERNEL) from inside an
> > interrupt handler. Oops.
>
> We're calling dev_alloc_skb() from hard interrupt context, but it uses
> GFP_ATOMIC, not GFP_KERNEL, so this is OK, right? I don't see the
> problem with e1000.
Neither do I, where is the detailed backtrace of this GFP_KERNEL
allocation supposedly from interrupt context?
^ permalink raw reply [flat|nested] 14+ messages in thread
* RE: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
@ 2004-05-25 21:20 Feldman, Scott
2004-05-25 21:47 ` David S. Miller
2004-05-25 22:53 ` Marcelo Tosatti
0 siblings, 2 replies; 14+ messages in thread
From: Feldman, Scott @ 2004-05-25 21:20 UTC (permalink / raw)
To: Marcelo Tosatti, Doug Dumitru
Cc: linux-kernel, cramerj, Ronciak, John, Venkatesan, Ganesh, jgarzik
Marcelo Tosatti wrote:
> It seems we are calling alloc_skb(GFP_KERNEL) from inside an
> interrupt handler. Oops.
We're calling dev_alloc_skb() from hard interrupt context, but it uses
GFP_ATOMIC, not GFP_KERNEL, so this is OK, right? I don't see the
problem with e1000.
> e1000 maintainers, can you look at this please?
-scott
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
2004-05-24 3:08 Doug Dumitru
@ 2004-05-25 19:02 ` Marcelo Tosatti
0 siblings, 0 replies; 14+ messages in thread
From: Marcelo Tosatti @ 2004-05-25 19:02 UTC (permalink / raw)
To: Doug Dumitru
Cc: linux-kernel, cramerj, john.ronciak, Ganesh.Venkatesan, jgarzik
On Sun, May 23, 2004 at 08:08:38PM -0700, Doug Dumitru wrote:
> I pulled some more information (if I did it correctly) from the first stack
> dump from the first __alloc_pages error log.
>
> ksymoops 2.4.4 on i686 2.4.25. Options used
> -V (default)
> -k ksyms.5 (specified)
> -l /proc/modules (default)
> -o /lib/modules/2.4.26/ (specified)
> -m /boot/System.map-2.4.26 (specified)
>
> Warning (expand_objects): object
> /lib/modules/2.4.26/kernel/drivers/md/lvm-mod.o for module lvm-mod has
> changed since load
> Warning (expand_objects): object /lib/modules/2.4.26/kernel/drivers/md/md.o
> for module md has changed since load
> cc68bad8 c0135289 00000000 011410ac 00000001 0000000c c03689dc 0000
> cbccb780 cbccb780 c02d23ba c7c5b838
> Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>]
> [<c01327f1>]
> [<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>]
> [<c01f05ec>]
> [<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>]
> [<c0134271>]
> [<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>]
> [<c029634f>]
> [<c014c467>] [<c014c8e9>] [<c010a72d>] [<c0108b63>]
> Warning (Oops_read): Code line not seen, dumping what data is available
>
> Trace; c0135289 <__alloc_pages+2d9/2f0>
> Trace; c01352b0 <__get_free_pages+10/20>
> Trace; c0132214 <kmem_cache_grow+c4/250>
> Trace; c02d23ba <arp_process+48a/4a0>
> Trace; c01327f1 <kmalloc+151/180>
> Trace; c029923f <alloc_skb+ef/1c0>
> Trace; c01f0d3c <e1000_alloc_rx_buffers+dc/110>
> Trace; c01f0c52 <e1000_clean_rx_irq+402/410>
> Trace; c0121786 <update_wall_time+16/50>
> Trace; c01219d9 <timer_bh+39/3f0>
> Trace; c01f05ec <e1000_intr+8c/e0>
> Trace; c010a4de <handle_IRQ_event+5e/90>
> Trace; c010a6f4 <do_IRQ+a4/f0>
> Trace; c0133ce6 <shrink_cache+a6/420>
> Trace; c0134152 <refill_inactive+f2/160>
> Trace; c01341fc <shrink_caches+3c/50>
> Trace; c0134271 <try_to_free_pages_zone+61/e0>
> Trace; c0134dff <balance_classzone+4f/200>
> Trace; c0135169 <__alloc_pages+1b9/2f0>
> Trace; c01352b0 <__get_free_pages+10/20>
> Trace; c014c203 <__pollwait+33/90>
> Trace; c02b765e <tcp_poll+2e/150>
> Trace; c029634f <sock_poll+1f/30>
> Trace; c014c467 <do_select+127/240>
> Trace; c014c8e9 <sys_select+339/480>
> Trace; c010a72d <do_IRQ+dd/f0>
> Trace; c0108b63 <system_call+33/38>
>
>
> If I am reading this correctly, the system was ...
>
> in an interrupt
> processing some TCP select(...) stuff
> asking for a page
> doing a zone rebalance
> trying to shrink cache
> and interrupted again
> by the ethernet driver
> which wanted to allocate an skb
> which wanted a page
>
> Thus __alloc_pages appears to be called recursively, with the 2nd call
> during a rebalance in the first one and both calls non-interuptable (on
> interrupts). Is this allowable?
Nope, this is not allowed.
It seems we are calling alloc_skb(GFP_KERNEL) from
inside an interrupt handler. Oops.
e1000 maintainers, can you look at this please?
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory
@ 2004-05-24 3:08 Doug Dumitru
2004-05-25 19:02 ` Marcelo Tosatti
0 siblings, 1 reply; 14+ messages in thread
From: Doug Dumitru @ 2004-05-24 3:08 UTC (permalink / raw)
To: linux-kernel
I pulled some more information (if I did it correctly) from the first stack dump from the first
__alloc_pages error log.
ksymoops 2.4.4 on i686 2.4.25. Options used
-V (default)
-k ksyms.5 (specified)
-l /proc/modules (default)
-o /lib/modules/2.4.26/ (specified)
-m /boot/System.map-2.4.26 (specified)
Warning (expand_objects): object /lib/modules/2.4.26/kernel/drivers/md/lvm-mod.o for module lvm-mod
has changed since load
Warning (expand_objects): object /lib/modules/2.4.26/kernel/drivers/md/md.o for module md has
changed since load
cc68bad8 c0135289 00000000 011410ac 00000001 0000000c c03689dc 0000 cbccb780 cbccb780 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>] [<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>] [<c01f05ec>]
[<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>] [<c0134271>]
[<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>]
[<c014c467>] [<c014c8e9>] [<c010a72d>] [<c0108b63>]
Warning (Oops_read): Code line not seen, dumping what data is available
Trace; c0135289 <__alloc_pages+2d9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c0132214 <kmem_cache_grow+c4/250>
Trace; c02d23ba <arp_process+48a/4a0>
Trace; c01327f1 <kmalloc+151/180>
Trace; c029923f <alloc_skb+ef/1c0>
Trace; c01f0d3c <e1000_alloc_rx_buffers+dc/110>
Trace; c01f0c52 <e1000_clean_rx_irq+402/410>
Trace; c0121786 <update_wall_time+16/50>
Trace; c01219d9 <timer_bh+39/3f0>
Trace; c01f05ec <e1000_intr+8c/e0>
Trace; c010a4de <handle_IRQ_event+5e/90>
Trace; c010a6f4 <do_IRQ+a4/f0>
Trace; c0133ce6 <shrink_cache+a6/420>
Trace; c0134152 <refill_inactive+f2/160>
Trace; c01341fc <shrink_caches+3c/50>
Trace; c0134271 <try_to_free_pages_zone+61/e0>
Trace; c0134dff <balance_classzone+4f/200>
Trace; c0135169 <__alloc_pages+1b9/2f0>
Trace; c01352b0 <__get_free_pages+10/20>
Trace; c014c203 <__pollwait+33/90>
Trace; c02b765e <tcp_poll+2e/150>
Trace; c029634f <sock_poll+1f/30>
Trace; c014c467 <do_select+127/240>
Trace; c014c8e9 <sys_select+339/480>
Trace; c010a72d <do_IRQ+dd/f0>
Trace; c0108b63 <system_call+33/38>
If I am reading this correctly, the system was ...
in an interrupt
processing some TCP select(...) stuff
asking for a page
doing a zone rebalance
trying to shrink cache
and interrupted again
by the ethernet driver
which wanted to allocate an skb
which wanted a page
Thus __alloc_pages appears to be called recursively, with the 2nd call during a rebalance in the
first one and both calls non-interuptable (on interrupts). Is this allowable?
--------------------------------------------------------------------
Doug Dumitru 800-470-2756 (610-237-2000)
EasyCo LLC doug@easyco.com http://easyco.com
--------------------------------------------------------------------
^ permalink raw reply [flat|nested] 14+ messages in thread
* Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory.
@ 2004-05-23 21:54 Doug Dumitru
0 siblings, 0 replies; 14+ messages in thread
From: Doug Dumitru @ 2004-05-23 21:54 UTC (permalink / raw)
To: linux-kernel
Personal replies gladly accepted at "doug at easyco.com"
I have a production system that will run for several hours and then rapidly degrade and finally
start spitting out a 0-order allocation failed message on the console in an endless loop. The time
from performance degredation to hard hang is 2 to 10 minutes.
Hardware: Dual Xeon 3.06GHz
8 Gig RAM
Raid disk array on Adaptec I2O controller
1Gbit LAN
Kernels tried: 2.4.20 4Gig
2.4.25 4Gig
2.4.25 64Gig
2.4.26 4Gig
2.4.26 64Gig
Filesystem: RedHat 7.3
Applications: Terminal-based distribution system running on
"D3" database with ~240 live users.
The system crashes with a swap partition (1Gig) and with no swap partition. In trying to determine
what was happening, I started a cron logger to log the output of cat /proc/meminfo to see if there
were symptoms leading up to the crash.
Here is a log transition across one crash
MemTotal is constant at 8274016
HighTotal is constant at 7471040
LowTotal is constant at 802976
MFree Bufs Cached Active Inactive HighFree LowFree
09:40:00 10172 31812 7284408 2813124 4687520 1044 9128
09:41:01 18400 31600 7276472 2780948 4711328 9192 9208
09:42:12 10756 31480 7282428 2740084 4758444 2820 7936
09:43:00 10404 30632 7281524 2708496 4789292 2712 7692
09:44:01 7640 29576 7280824 2662620 4835340 1500 6140
... note that the next log job takes an extra 38 seconds to run because
loadavg was >100 at this point
09:45:39 6996 29424 7282088 2580316 4917912 1084 5912
... system hangs and is rebooted
09:55:00 7634392 17160 535912 535912 39024 7390488 243904
I have been trying to find a set of jobs that reproduces this crash, but have not been able to
without actually running live users (which is not desireable).
One behaviour that I am somewhat concerned about is that LowFree drops to <10Megabytes and stays
there with this job mix while my tests to stress the system tend to leave 240Meg to 300Meg of
LowFree available. I was under the impression that the kernel tries to maintain a certain amount of
LowFree available based on tunable entries in /proc.
The user is currently running the same application on a slightly older (Dual 1.7 Xeon w/ 4G RAM)
system and their memory usage is similar, but they don't get the hang. Their current /proc/meminfo is:
[root@... /root]# cat /proc/meminfo
total: used: free: shared: buffers: cached:
Mem: 3443044352 3413295104 29749248 0 79945728 2947735552
Swap: 1077469184 144068608 933400576
MemTotal: 3362348 kB
MemFree: 29052 kB
MemShared: 0 kB
Buffers: 78072 kB
Cached: 2852116 kB
SwapCached: 26532 kB
Active: 1587692 kB
Inactive: 1378096 kB
HighTotal: 2489280 kB
HighFree: 10668 kB
LowTotal: 873068 kB
LowFree: 18384 kB (this seems awful low to me)
SwapTotal: 1052216 kB
SwapFree: 911524 kB
[root@... /root]# uptime
11:34pm up 9 days, 2:52, 4 users, load average: 0.00, 0.00, 0.00
The actual crash dump is:
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
cc68bad8 c0135289 00000000 011410ac 00000001 0000000c c03689dc 0000 cbccb780 cbccb780 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>] [<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>] [<c01f05ec>]
[<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>] [<c0134271>]
[<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>]
[<c014c467>] [<c014c8e9>] [<c010a72d>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d8c77c38 c0135289 00000000 de22f034 00000001 0000000c c03689dc c0368b94
00000000 00000020 00000000 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 dbb0c000 c0725980 c0725980 011410ac c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c01327f1>] [<c029923f>]
[<c01f0d3c>] [<c01f0c52>] [<c0121c57>] [<c01f05ec>] [<c010a4de>] [<c010a6f4>]
[<c0133ce6>] [<c0134152>] [<c01341fc>] [<c0134271>] [<c0134dff>] [<c0135169>]
[<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>] [<c014c467>] [<c014c8e9>]
[<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d8c77c38 c0135289 00000000 de22f034 00000001 0000000c c03689dc c0368b94
00000000 00000020 00000000 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000000 c0725980 c0725980 011410ac c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c01327f1>] [<c029923f>]
[<c01f0d3c>] [<c01f0c52>] [<c0121c57>] [<c01f05ec>] [<c010a4de>] [<c010a6f4>]
[<c0133ce6>] [<c0134152>] [<c01341fc>] [<c0134271>] [<c0134dff>] [<c0135169>]
[<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>] [<c014c467>] [<c014c8e9>]
[<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d8c77c38 c0135289 00000000 f598a880 00000001 0000000c c03689dc c0368b94
00000000 00000020 c7cb0000 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 c029957c c0d14d80 c0d14d80 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c029957c>] [<c02d23ba>]
[<c01327f1>] [<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>]
[<c01f05ec>] [<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>]
[<c0134271>] [<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>]
[<c029634f>] [<c014c467>] [<c014c8e9>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d8c77c38 c0135289 00000000 f598a880 00000001 0000000c c03689dc c0368b94
00000000 00000020 c7cb0000 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000000 c0d14d80 c0d14d80 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c02d23ba>] [<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>] [<c01f05ec>]
[<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>] [<c0134271>]
[<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>]
[<c014c467>] [<c014c8e9>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d93e9c5c c0135289 00000000 f598a880 00000001 0000000c c03689dc c0368b94
00000000 00000020 c02b3b74 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 c029957c c0751b80 c0751b80 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c02b3b74>] [<c01352b0>] [<c0132214>] [<c029957c>]
[<c02d23ba>] [<c01327f1>] [<c029923f>] [<c01f0d3c>] [<c02c6a91>] [<c01f0c52>]
[<c02c7300>] [<c0121c57>] [<c01f05ec>] [<c010a4de>] [<c010a6f4>] [<c0133d77>]
[<c0134152>] [<c01341fc>] [<c0134271>] [<c0134dff>] [<c0135169>] [<c01352b0>]
[<c014c203>] [<c0146559>] [<c014c467>] [<c014c8e9>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
d93e9c5c c0135289 00000000 f598a880 00000001 0000000c c03689dc c0368b94
00000000 00000020 c02b3b74 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000000 c0751b80 c0751b80 c02d23ba c7c5b838
Call Trace: [<c0135289>] [<c02b3b74>] [<c01352b0>] [<c0132214>] [<c02d23ba>]
[<c01327f1>] [<c029923f>] [<c01f0d3c>] [<c02c6a91>] [<c01f0c52>] [<c02c7300>]
[<c0121c57>] [<c01f05ec>] [<c010a4de>] [<c010a6f4>] [<c0133d77>] [<c0134152>]
[<c01341fc>] [<c0134271>] [<c0134dff>] [<c0135169>] [<c01352b0>] [<c014c203>]
[<c0146559>] [<c014c467>] [<c014c8e9>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
e1b73c38 c0135289 00000000 00000002 00000001 0000000c c03689dc c0368b94
00000000 00000020 dad83880 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000000 c0eb9080 c0eb9080 011410ac c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c01327f1>] [<c029923f>]
[<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>] [<c01f05ec>] [<c010a4de>]
[<c010a6f4>] [<c0133d0f>] [<c0134152>] [<c01341fc>] [<c0134271>] [<c0134dff>]
[<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>] [<c014c467>]
[<c014c8e9>] [<c010a72d>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
e1b73c38 c0135289 00000000 00000002 00000001 0000000c c03689dc c0368b94
00000000 00000020 dad83880 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000000 c0eb9080 c0eb9080 011410ac c7c5b838
Call Trace: [<c0135289>] [<c01352b0>] [<c0132214>] [<c01327f1>] [<c029923f>]
[<c01f0d3c>] [<c01f0c52>] [<c0121786>] [<c01219d9>] [<c01f05ec>] [<c010a4de>]
[<c010a6f4>] [<c0133d0f>] [<c0134152>] [<c01341fc>] [<c0134271>] [<c0134dff>]
[<c0135169>] [<c01352b0>] [<c014c203>] [<c02b765e>] [<c029634f>] [<c014c467>]
[<c014c8e9>] [<c010a72d>] [<c0108b63>]
__alloc_pages: 0-order allocation failed (gfp=0x20/1)
dccf7c38 c0135289 00000000 c07bf034 00000001 0000000c c03689dc c0368b94
00000000 00000020 c02b3b74 00000000 c7c5b838 00000020 00000000 c01352b0
c0132214 00000003 00000020 00000001 00000020 f6d3f270 ffffffff c7c5b838
Call Trace: [<c0135289>] [<c02b3b74>] [<c01352b0>] [<c0132214>] [<c01327f1>]
[<c029923f>] [<c01f0d3c>] [<c02c6a91>] [<c01f0c52>] [<c02c7300>] [<c0121c57>]
[<c01f05ec>] [<c010a4de>] [<c010a6f4>] [<c0133ce6>] [<c0134152>] [<c01341fc>]
This looks to me like the memory manager stops trying to re-tune available low memory (although I
might be very off-base). Any explanation of how the memory manager tries to maintain available High
and Low memory ratios would be greatly appreciated. Also, what processes, if any, take and keep low
memory to the point that the system can end up with <10Meg on such a large memory system.
Thank you,
--------------------------------------------------------------------
Doug Dumitru 800-470-2756 (610-237-2000)
EasyCo LLC doug at easyco.com http://easyco.com
--------------------------------------------------------------------
^ permalink raw reply [flat|nested] 14+ messages in thread
end of thread, other threads:[~2004-05-26 20:04 UTC | newest]
Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2004-05-25 22:26 Hard Hang with __alloc_pages: 0-order allocation failed (gfp=0x20/1) - Not out of memory Doug Dumitru
2004-05-25 23:12 ` David S. Miller
2004-05-26 12:59 ` Marcelo Tosatti
2004-05-26 18:59 ` Doug Dumitru
-- strict thread matches above, loose matches on Subject: below --
2004-05-26 1:22 (Found?) " Roger Larsson
2004-05-26 19:58 ` Roger Larsson
2004-05-25 22:17 Doug Dumitru
2004-05-25 21:20 Feldman, Scott
2004-05-25 21:47 ` David S. Miller
2004-05-25 22:53 ` Marcelo Tosatti
2004-05-25 23:39 ` Marcelo Tosatti
2004-05-25 22:53 ` Marcelo Tosatti
2004-05-24 3:08 Doug Dumitru
2004-05-25 19:02 ` Marcelo Tosatti
2004-05-23 21:54 Doug Dumitru
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).