Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Eric Dumazet]

Le vendredi 04 juin 2010 à 11:20 +0200, Michael Guntsche a écrit :
> Hi list,
> 
> Testing 2.6.35-rc1 on my powerpc based routerboard I saw the following page allocation
> error happening during an apt-get update with a semi loaded wlan
> interface
> 
> [309611.189267] __alloc_pages_slowpath: 52 callbacks suppressed
> [309611.194959] gzip: page allocation failure. order:1, mode:0x4020
> [309611.200981] Call Trace:
> [309611.203547] [c399bc50] [c0008144] show_stack+0x48/0x15c (unreliable)
> [309611.210041] [c399bc80] [c006268c] __alloc_pages_nodemask+0x3d4/0x52c
> [309611.216512] [c399bd20] [c008619c] __slab_alloc+0x560/0x570
> [309611.222111] [c399bd60] [c0086a98] __kmalloc_track_caller+0xd4/0x104
> [309611.228505] [c399bd80] [c01dd220] __alloc_skb+0x64/0x124
> [309611.233944] [c399bda0] [c994e034] ath_rxbuf_alloc+0x34/0xbc [ath]
> [309611.240178] [c399bdc0] [c9a1ec9c] ath_rx_tasklet+0x480/0x7c4 [ath9k]
> [309611.246658] [c399be80] [c9a1dae0] ath9k_tasklet+0x114/0x13c [ath9k]
> [309611.253055] [c399bea0] [c002532c] tasklet_action+0x88/0x104
> [309611.258746] [c399bec0] [c0025e30] __do_softirq+0xb4/0x134
> [309611.264261] [c399bf00] [c0005ec4] do_softirq+0x58/0x5c
> [309611.269514] [c399bf10] [c0025c20] irq_exit+0x7c/0x9c
> [309611.274591] [c399bf20] [c0005f64] do_IRQ+0x9c/0xb4
> [309611.279509] [c399bf40] [c00117d8] ret_from_except+0x0/0x14
> [309611.285112] --- Exception: 501 at 0xff31f0c
> [309611.285121]     LR = 0xff32548
> [309611.292536] Mem-Info:
> [309611.294899] DMA per-cpu:
> [309611.297528] CPU    0: hi:   42, btch:   7 usd:  18
> [309611.302444] active_anon:1040 inactive_anon:1160 isolated_anon:0
> [309611.302455]  active_file:14871 inactive_file:9440 isolated_file:0
> [309611.302467]  unevictable:491 dirty:1258 writeback:0 unstable:0
> [309611.302478]  free:628 slab_reclaimable:832 slab_unreclaimable:2312
> [309611.302490]  mapped:2254 shmem:36 pagetables:202 bounce:0
> [309611.332409] DMA free:2512kB min:1440kB low:1800kB high:2160kB active_anon:4160kB inactive_anon:4640kB active_file:59484kB inactive_file:37760kB unevictable:1964kB isolated(anon):0kB isolated(file):0kB present:130048kB mlocked:1964kB dirty:5032kB writeback:0kB mapped:9016kB shmem:144kB slab_reclaimable:3328kB slab_unreclaimable:9248kB kernel_stack:528kB pagetables:808kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> [309611.372230] lowmem_reserve[]: 0 0 0
> [309611.375835] DMA: 596*4kB 14*8kB 1*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2512kB
> [309611.386215] 24770 total pagecache pages
> [309611.390147] 0 pages in swap cache
> [309611.393559] Swap cache stats: add 0, delete 0, find 0/0
> [309611.398884] Free swap  = 0kB
> [309611.401857] Total swap = 0kB
> [309611.411877] 32768 pages RAM
> [309611.414765] 1228 pages reserved
> [309611.418000] 27690 pages shared
> [309611.421147] 8802 pages non-shared
> [309611.424560] SLUB: Unable to allocate memory on node -1 (gfp=0x20)
> [309611.430764]   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default order: 3, min order: 1
> [309611.440276]   node 0: slabs: 155, objs: 620, free: 0
> [309611.445439] skbuff alloc of size 3872 failed

order-1 allocations are unfortunate, since this hardware should use
order-0 ones if possible, and it seems it was its goal.

3872 (0xF20) comes from 

#define IEEE80211_MAX_MPDU_LEN     (3840 + FCS_LEN +
	(IEEE80211_WEP_IVLEN +  \
	IEEE80211_WEP_KIDLEN + \
	IEEE80211_WEP_CRCLEN))

common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
	ah->caps.rx_status_len,
	min(common->cachelsz, (u16)64));

Then __dev_alloc_skb() adds two more blocs :

NET_SKB_PAD  (64 bytes on your platform ?)

sizeof(struct skb_shared_info) 
(on 32bit : 0x104 ... oh well that might be the problem : it is rounded
to 0x140)


And ath driver adds common->cachelsz  (I dont know its value)

-> more than 4096 bytes

1) Maybe rx_bufsize should not include the roundup() since 
ath_rxbuf_alloc() also do an alignment adjustment ?

2) We should try to reduce skb_shared_info by four bytes.

Could you try this patch ?


We make sure rx_bufsize + various overhead <= PAGE_SIZE
But I am not sure its legal for the hardware...

diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
index ca6065b..0a0dc3a 100644
--- a/drivers/net/wireless/ath/ath9k/recv.c
+++ b/drivers/net/wireless/ath/ath9k/recv.c
@@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
 	u32 size;
 
 
-	common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
-				     ah->caps.rx_status_len,
-				     min(common->cachelsz, (u16)64));
-
+	size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
+		       min(common->cachelsz, (u16)64));
+	common->rx_bufsize = max_t(u32, size,
+				   SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
 	ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
 				    ah->caps.rx_status_len);
 

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Michael Guntsche]

On 2010.06.04 14:53:34 , Eric Dumazet wrote:
> order-1 allocations are unfortunate, since this hardware should use
> order-0 ones if possible, and it seems it was its goal.
> 
> 3872 (0xF20) comes from 
<snip>
> 
> 1) Maybe rx_bufsize should not include the roundup() since 
> ath_rxbuf_alloc() also do an alignment adjustment ?
> 
> 2) We should try to reduce skb_shared_info by four bytes.
> 
> Could you try this patch ?
> 
> 
> We make sure rx_bufsize + various overhead <= PAGE_SIZE
> But I am not sure its legal for the hardware...

I applied the patch recompiled and run it on the routerboard, trying
to trigger the bug again.

Kind regards,
Michael

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Michael Guntsche]

On 2010.06.04 18:16:44 , Michael Guntsche wrote:
> I applied the patch recompiled and run it on the routerboard, trying
> to trigger the bug again.

Hi Eric,

Up to now I was not able to reproduce the bug, do you think this patch
can be pushed to mainline or is there a "better"/other  fix for it?

Kind regards,
Michael

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Eric Dumazet]

Le dimanche 06 juin 2010 à 11:56 +0200, Michael Guntsche a écrit :
> On 2010.06.04 18:16:44 , Michael Guntsche wrote:
> > I applied the patch recompiled and run it on the routerboard, trying
> > to trigger the bug again.
> 
> Hi Eric,
> 
> Up to now I was not able to reproduce the bug, do you think this patch
> can be pushed to mainline or is there a "better"/other  fix for it?
> 
> Kind regards,
> Michael
> 
> 

Thanks Michael for testing.

I'll submit ASAP an official patch, sent to all people involved in this
driver to get their Ack (or Nack).

IEEE80211_MAX_MPDU_LEN being 3840 + somebits is suspect, since it doesnt
match 802.11 specs.

It should be more close of 2304 + MAC header (32bytes) + FCS (4 bytes) ?

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Nikhil Sethi (निखिल सेठी)]

Hello.

I am running 2.5.35.3 with the above patch, and I still get these
failures. Though they are much less often than without the patch. A
snippet from dmesg below.

Please let me know what other details I should provide. Thanks

skbuff alloc of size 3872 failed
java: page allocation failure. order:1, mode:0x4020
Pid: 11464, comm: java Not tainted 2.6.35.3 #3
Call Trace:
 [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
 [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
 [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<c0334097>] ? __alloc_skb+0x57/0x100
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
 [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
 [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
 [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
 [<c02195bf>] ? tasklet_action+0x5f/0x65
 [<c0219873>] ? __do_softirq+0x60/0xc6
 [<c0219907>] ? do_softirq+0x2e/0x30
 [<c02199f9>] ? irq_exit+0x53/0x55
 [<c020392c>] ? do_IRQ+0x3a/0x72
 [<c0202be9>] ? common_interrupt+0x29/0x30
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  32
active_anon:6158 inactive_anon:15748 isolated_anon:0
 active_file:11477 inactive_file:22926 isolated_file:0
 unevictable:468 dirty:5788 writeback:0 unstable:0
 free:990 slab_reclaimable:3091 slab_unreclaimable:2349
 mapped:1410 shmem:5 pagetables:227 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:2960kB min:1908kB low:2384kB high:2860kB
active_anon:23328kB inactive_anon:60688kB active_file:43324kB
inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 1000kB
Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 2960kB
37964 total pagecache pages
3160 pages in swap cache
Swap cache stats: add 164954, delete 161794, find 97931/115609
Free swap  = 937284kB
Total swap = 963896kB
65535 pages RAM
1237 pages reserved
29042 pages shared
38802 pages non-shared
SLUB: Unable to allocate memory on node -1 (gfp=0x20)
  cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
order: 3, min order: 1
  node 0: slabs: 0, objs: 0, free: 0
skbuff alloc of size 3872 failed
java: page allocation failure. order:1, mode:0x4020
Pid: 11464, comm: java Not tainted 2.6.35.3 #3
Call Trace:
 [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
 [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
 [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<c0334097>] ? __alloc_skb+0x57/0x100
 [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
 [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
 [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
 [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
 [<c02195bf>] ? tasklet_action+0x5f/0x65
 [<c0219873>] ? __do_softirq+0x60/0xc6
 [<c0219907>] ? do_softirq+0x2e/0x30
 [<c02199f9>] ? irq_exit+0x53/0x55
 [<c020392c>] ? do_IRQ+0x3a/0x72
 [<c0202be9>] ? common_interrupt+0x29/0x30
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  32
active_anon:6158 inactive_anon:15748 isolated_anon:0
 active_file:11477 inactive_file:22926 isolated_file:0
 unevictable:468 dirty:5788 writeback:0 unstable:0
 free:990 slab_reclaimable:3091 slab_unreclaimable:2349
 mapped:1410 shmem:5 pagetables:227 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:2960kB min:1908kB low:2384kB high:2860kB
active_anon:23328kB inactive_anon:60688kB active_file:43324kB
inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 1000kB
Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 2960kB
37964 total pagecache pages
3160 pages in swap cache

On Sun, Jun 6, 2010 at 3:42 AM, Eric Dumazet <eric.dumazet@gmail.com> wrote:
>
> Le dimanche 06 juin 2010 à 11:56 +0200, Michael Guntsche a écrit :
> > On 2010.06.04 18:16:44 , Michael Guntsche wrote:
> > > I applied the patch recompiled and run it on the routerboard, trying
> > > to trigger the bug again.
> >
> > Hi Eric,
> >
> > Up to now I was not able to reproduce the bug, do you think this patch
> > can be pushed to mainline or is there a "better"/other  fix for it?
> >
> > Kind regards,
> > Michael
> >
> >
>
> Thanks Michael for testing.
>
> I'll submit ASAP an official patch, sent to all people involved in this
> driver to get their Ack (or Nack).
>
> IEEE80211_MAX_MPDU_LEN being 3840 + somebits is suspect, since it doesnt
> match 802.11 specs.
>
> It should be more close of 2304 + MAC header (32bytes) + FCS (4 bytes) ?
>
>
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/
>
>

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Eric Dumazet]

Le mercredi 25 août 2010 à 13:25 -0700, Nikhil Sethi (निखिल सेठी) a
écrit :
> Hello.
> 
> I am running 2.5.35.3 with the above patch, and I still get these
> failures. Though they are much less often than without the patch. A
> snippet from dmesg below.
> 
> Please let me know what other details I should provide. Thanks
> 
> skbuff alloc of size 3872 failed
> java: page allocation failure. order:1, mode:0x4020
> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
> Call Trace:
>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<c0334097>] ? __alloc_skb+0x57/0x100
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
>  [<c02195bf>] ? tasklet_action+0x5f/0x65
>  [<c0219873>] ? __do_softirq+0x60/0xc6
>  [<c0219907>] ? do_softirq+0x2e/0x30
>  [<c02199f9>] ? irq_exit+0x53/0x55
>  [<c020392c>] ? do_IRQ+0x3a/0x72
>  [<c0202be9>] ? common_interrupt+0x29/0x30
> Mem-Info:
> DMA per-cpu:
> CPU    0: hi:    0, btch:   1 usd:   0
> Normal per-cpu:
> CPU    0: hi:   90, btch:  15 usd:  32
> active_anon:6158 inactive_anon:15748 isolated_anon:0
>  active_file:11477 inactive_file:22926 isolated_file:0
>  unevictable:468 dirty:5788 writeback:0 unstable:0
>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
>  mapped:1410 shmem:5 pagetables:227 bounce:0
> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> lowmem_reserve[]: 0 238 238
> Normal free:2960kB min:1908kB low:2384kB high:2860kB
> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> lowmem_reserve[]: 0 0 0
> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 2960kB
> 37964 total pagecache pages
> 3160 pages in swap cache
> Swap cache stats: add 164954, delete 161794, find 97931/115609
> Free swap  = 937284kB
> Total swap = 963896kB
> 65535 pages RAM
> 1237 pages reserved
> 29042 pages shared
> 38802 pages non-shared
> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
> order: 3, min order: 1
>   node 0: slabs: 0, objs: 0, free: 0
> skbuff alloc of size 3872 failed
> java: page allocation failure. order:1, mode:0x4020
> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
> Call Trace:
>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<c0334097>] ? __alloc_skb+0x57/0x100
>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
>  [<c02195bf>] ? tasklet_action+0x5f/0x65
>  [<c0219873>] ? __do_softirq+0x60/0xc6
>  [<c0219907>] ? do_softirq+0x2e/0x30
>  [<c02199f9>] ? irq_exit+0x53/0x55
>  [<c020392c>] ? do_IRQ+0x3a/0x72
>  [<c0202be9>] ? common_interrupt+0x29/0x30
> Mem-Info:
> DMA per-cpu:
> CPU    0: hi:    0, btch:   1 usd:   0
> Normal per-cpu:
> CPU    0: hi:   90, btch:  15 usd:  32
> active_anon:6158 inactive_anon:15748 isolated_anon:0
>  active_file:11477 inactive_file:22926 isolated_file:0
>  unevictable:468 dirty:5788 writeback:0 unstable:0
>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
>  mapped:1410 shmem:5 pagetables:227 bounce:0
> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
> pages_scanned:0 all_unreclaimable? no
> lowmem_reserve[]: 0 238 238
> Normal free:2960kB min:1908kB low:2384kB high:2860kB
> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> lowmem_reserve[]: 0 0 0
> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 2960kB
> 37964 total pagecache pages
> 3160 pages in swap cache
> 
> On Sun, Jun 6, 2010 at 3:42 AM, Eric Dumazet <eric.dumazet@gmail.com> wrote:
> >
> > Le dimanche 06 juin 2010 à 11:56 +0200, Michael Guntsche a écrit :
> > > On 2010.06.04 18:16:44 , Michael Guntsche wrote:
> > > > I applied the patch recompiled and run it on the routerboard, trying
> > > > to trigger the bug again.
> > >
> > > Hi Eric,
> > >
> > > Up to now I was not able to reproduce the bug, do you think this patch
> > > can be pushed to mainline or is there a "better"/other  fix for it?
> > >
> > > Kind regards,
> > > Michael
> > >
> > >
> >
> > Thanks Michael for testing.
> >
> > I'll submit ASAP an official patch, sent to all people involved in this
> > driver to get their Ack (or Nack).
> >
> > IEEE80211_MAX_MPDU_LEN being 3840 + somebits is suspect, since it doesnt
> > match 802.11 specs.
> >
> > It should be more close of 2304 + MAC header (32bytes) + FCS (4 bytes) ?
> >
> >
> >
> > --


reading my former patch, I believe I mistakenly used a max_t() instead
of a min_() macro :

diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
index ca6065b..0a0dc3a 100644
--- a/drivers/net/wireless/ath/ath9k/recv.c
+++ b/drivers/net/wireless/ath/ath9k/recv.c
@@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
        u32 size;
 
 
-       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
-                                    ah->caps.rx_status_len,
-                                    min(common->cachelsz, (u16)64));
-
+       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
+                      min(common->cachelsz, (u16)64));
+       common->rx_bufsize = max_t(u32, size,
+                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
                                    ah->caps.rx_status_len);
 


Please use instead this one :

diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
index ca6065b..0a0dc3a 100644
--- a/drivers/net/wireless/ath/ath9k/recv.c
+++ b/drivers/net/wireless/ath/ath9k/recv.c
@@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
        u32 size;
 
 
-       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
-                                    ah->caps.rx_status_len,
-                                    min(common->cachelsz, (u16)64));
-
+       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
+                      min(common->cachelsz, (u16)64));
+       common->rx_bufsize = min_t(u32, size,
+                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
                                    ah->caps.rx_status_len);
 

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Nikhil Sethi (निखिल सेठी)]

Thanks Eric. I have not been able to reproduce this problem after
applying your new patch in about 12 hours of operation. Will let you
know if the bug re-appears.

Thanks
Nikhil

2010/8/25 Eric Dumazet <eric.dumazet@gmail.com>:
> Le mercredi 25 août 2010 à 13:25 -0700, Nikhil Sethi (निखिल सेठी) a
> écrit :
>> Hello.
>>
>> I am running 2.5.35.3 with the above patch, and I still get these
>> failures. Though they are much less often than without the patch. A
>> snippet from dmesg below.
>>
>> Please let me know what other details I should provide. Thanks
>>
>> skbuff alloc of size 3872 failed
>> java: page allocation failure. order:1, mode:0x4020
>> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
>> Call Trace:
>>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
>>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
>>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<c0334097>] ? __alloc_skb+0x57/0x100
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
>>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
>>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
>>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
>>  [<c02195bf>] ? tasklet_action+0x5f/0x65
>>  [<c0219873>] ? __do_softirq+0x60/0xc6
>>  [<c0219907>] ? do_softirq+0x2e/0x30
>>  [<c02199f9>] ? irq_exit+0x53/0x55
>>  [<c020392c>] ? do_IRQ+0x3a/0x72
>>  [<c0202be9>] ? common_interrupt+0x29/0x30
>> Mem-Info:
>> DMA per-cpu:
>> CPU    0: hi:    0, btch:   1 usd:   0
>> Normal per-cpu:
>> CPU    0: hi:   90, btch:  15 usd:  32
>> active_anon:6158 inactive_anon:15748 isolated_anon:0
>>  active_file:11477 inactive_file:22926 isolated_file:0
>>  unevictable:468 dirty:5788 writeback:0 unstable:0
>>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
>>  mapped:1410 shmem:5 pagetables:227 bounce:0
>> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
>> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
>> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
>> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
>> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
>> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
>> pages_scanned:0 all_unreclaimable? no
>> lowmem_reserve[]: 0 238 238
>> Normal free:2960kB min:1908kB low:2384kB high:2860kB
>> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
>> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
>> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
>> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
>> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
>> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
>> all_unreclaimable? no
>> lowmem_reserve[]: 0 0 0
>> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 1000kB
>> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 2960kB
>> 37964 total pagecache pages
>> 3160 pages in swap cache
>> Swap cache stats: add 164954, delete 161794, find 97931/115609
>> Free swap  = 937284kB
>> Total swap = 963896kB
>> 65535 pages RAM
>> 1237 pages reserved
>> 29042 pages shared
>> 38802 pages non-shared
>> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
>> order: 3, min order: 1
>>   node 0: slabs: 0, objs: 0, free: 0
>> skbuff alloc of size 3872 failed
>> java: page allocation failure. order:1, mode:0x4020
>> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
>> Call Trace:
>>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
>>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
>>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<c0334097>] ? __alloc_skb+0x57/0x100
>>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
>>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
>>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
>>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
>>  [<c02195bf>] ? tasklet_action+0x5f/0x65
>>  [<c0219873>] ? __do_softirq+0x60/0xc6
>>  [<c0219907>] ? do_softirq+0x2e/0x30
>>  [<c02199f9>] ? irq_exit+0x53/0x55
>>  [<c020392c>] ? do_IRQ+0x3a/0x72
>>  [<c0202be9>] ? common_interrupt+0x29/0x30
>> Mem-Info:
>> DMA per-cpu:
>> CPU    0: hi:    0, btch:   1 usd:   0
>> Normal per-cpu:
>> CPU    0: hi:   90, btch:  15 usd:  32
>> active_anon:6158 inactive_anon:15748 isolated_anon:0
>>  active_file:11477 inactive_file:22926 isolated_file:0
>>  unevictable:468 dirty:5788 writeback:0 unstable:0
>>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
>>  mapped:1410 shmem:5 pagetables:227 bounce:0
>> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
>> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
>> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
>> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
>> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
>> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
>> pages_scanned:0 all_unreclaimable? no
>> lowmem_reserve[]: 0 238 238
>> Normal free:2960kB min:1908kB low:2384kB high:2860kB
>> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
>> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
>> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
>> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
>> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
>> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
>> all_unreclaimable? no
>> lowmem_reserve[]: 0 0 0
>> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 1000kB
>> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 2960kB
>> 37964 total pagecache pages
>> 3160 pages in swap cache
>>
>> On Sun, Jun 6, 2010 at 3:42 AM, Eric Dumazet <eric.dumazet@gmail.com> wrote:
>> >
>> > Le dimanche 06 juin 2010 à 11:56 +0200, Michael Guntsche a écrit :
>> > > On 2010.06.04 18:16:44 , Michael Guntsche wrote:
>> > > > I applied the patch recompiled and run it on the routerboard, trying
>> > > > to trigger the bug again.
>> > >
>> > > Hi Eric,
>> > >
>> > > Up to now I was not able to reproduce the bug, do you think this patch
>> > > can be pushed to mainline or is there a "better"/other  fix for it?
>> > >
>> > > Kind regards,
>> > > Michael
>> > >
>> > >
>> >
>> > Thanks Michael for testing.
>> >
>> > I'll submit ASAP an official patch, sent to all people involved in this
>> > driver to get their Ack (or Nack).
>> >
>> > IEEE80211_MAX_MPDU_LEN being 3840 + somebits is suspect, since it doesnt
>> > match 802.11 specs.
>> >
>> > It should be more close of 2304 + MAC header (32bytes) + FCS (4 bytes) ?
>> >
>> >
>> >
>> > --
>
>
> reading my former patch, I believe I mistakenly used a max_t() instead
> of a min_() macro :
>
> diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
> index ca6065b..0a0dc3a 100644
> --- a/drivers/net/wireless/ath/ath9k/recv.c
> +++ b/drivers/net/wireless/ath/ath9k/recv.c
> @@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
>        u32 size;
>
>
> -       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> -                                    ah->caps.rx_status_len,
> -                                    min(common->cachelsz, (u16)64));
> -
> +       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> +                      min(common->cachelsz, (u16)64));
> +       common->rx_bufsize = max_t(u32, size,
> +                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
>        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
>                                    ah->caps.rx_status_len);
>
>
>
> Please use instead this one :
>
> diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
> index ca6065b..0a0dc3a 100644
> --- a/drivers/net/wireless/ath/ath9k/recv.c
> +++ b/drivers/net/wireless/ath/ath9k/recv.c
> @@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
>        u32 size;
>
>
> -       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> -                                    ah->caps.rx_status_len,
> -                                    min(common->cachelsz, (u16)64));
> -
> +       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> +                      min(common->cachelsz, (u16)64));
> +       common->rx_bufsize = min_t(u32, size,
> +                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
>        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
>                                    ah->caps.rx_status_len);
>
>
>
>
>

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Nikhil Sethi (निखिल सेठी)]

This came back. Here is the dmesg output. It might be the problem only
happens if I have wmm_enabled=1 in my hostapd.conf. That is the only
thing that I changed yesterday, and today I saw these messages in my
logs. I will try to conform this.

I am running 2.6.35.4 with this patch:

*** 225,234 ****
  	int error = 0, i;
  	u32 size;

!
! 	common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
! 				     ah->caps.rx_status_len,
! 				     min(common->cachelsz, (u16)64));

  	ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
  				    ah->caps.rx_status_len);
--- 225,234 ----
  	int error = 0, i;
  	u32 size;

! 	size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
!                        min(common->cachelsz, (u16)64));
!         common->rx_bufsize = min_t(u32, size,
!                                    SKB_MAX_ORDER(NET_SKB_PAD +
common->cachelsz, 0));

  	ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
  				    ah->caps.rx_status_len);

dmesg output:

skbuff alloc of size 3872 failed
ps: page allocation failure. order:1, mode:0x4020
Pid: 16022, comm: ps Tainted: G        W   2.6.35.4 #1
Call Trace:
 [<c0243bfe>] ? __alloc_pages_nodemask+0x3e6/0x513
 [<c025be97>] ? slob_new_pages+0xc/0x23
 [<c025c0a1>] ? __kmalloc_node+0x39/0x72
 [<c03338d8>] ? __alloc_skb+0x5c/0x105
 [<d09fa01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0ab7109>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
 [<c030fd49>] ? scsi_next_command+0x27/0x34
 [<d0ab53c5>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
 [<c02193c3>] ? tasklet_action+0x5f/0x65
 [<c0219677>] ? __do_softirq+0x60/0xc6
 [<c021970b>] ? do_softirq+0x2e/0x30
 [<c02197fd>] ? irq_exit+0x53/0x55
 [<c020392c>] ? do_IRQ+0x3a/0x72
 [<c0202be9>] ? common_interrupt+0x29/0x30
 [<c0247874>] ? __remove_mapping+0x4b/0x8d
 [<c023ea9f>] ? try_to_release_page+0x20/0x30
 [<c0247d36>] ? shrink_page_list+0x2b8/0x46c
 [<c03158ea>] ? sd_prep_fn+0x1a5/0x92b
 [<c024816b>] ? shrink_inactive_list+0x281/0x552
 [<c02445d9>] ? determine_dirtyable_memory+0xc/0x12
 [<c024462c>] ? get_dirty_limits+0x18/0x2b0
 [<c032875e>] ? ata_bmdma_port_intr+0x21/0xcd
 [<c0248683>] ? shrink_zone+0x247/0x38f
 [<c021968c>] ? __do_softirq+0x75/0xc6
 [<c0247114>] ? shrink_slab+0x13c/0x186
 [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
 [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
 [<c0243acf>] ? __alloc_pages_nodemask+0x2b7/0x513
 [<c025be97>] ? slob_new_pages+0xc/0x23
 [<c025c038>] ? kmem_cache_alloc_node+0x23/0x53
 [<c0264b20>] ? getname+0x19/0xae
 [<c0266d00>] ? user_path_at+0x11/0x64
 [<c0250949>] ? access_process_vm+0xe0/0x1e7
 [<c0250a08>] ? access_process_vm+0x19f/0x1e7
 [<c02603d2>] ? vfs_fstatat+0x25/0x63
 [<c02604a9>] ? vfs_stat+0x10/0x12
 [<c02604ba>] ? sys_stat64+0xf/0x23
 [<c025e86b>] ? fput+0x88/0x191
 [<c026ab3b>] ? dput+0x92/0xd4
 [<c025e8ff>] ? fput+0x11c/0x191
 [<c026ebec>] ? mntput_no_expire+0x13/0x60
 [<c025c398>] ? filp_close+0x3b/0x54
 [<c025c403>] ? sys_close+0x52/0x72
 [<c038ad3d>] ? syscall_call+0x7/0xb
 [<c0380000>] ? unix_dgram_sendmsg+0x258/0x3c1
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  79
active_anon:7578 inactive_anon:15111 isolated_anon:0
 active_file:11157 inactive_file:20027 isolated_file:32
 unevictable:467 dirty:1159 writeback:0 unstable:0
 free:706 slab_reclaimable:0 slab_unreclaimable:0
 mapped:2183 shmem:0 pagetables:278 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:860kB
inactive_anon:2280kB active_file:3664kB inactive_file:4876kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
mlocked:0kB dirty:8kB writeback:0kB mapped:1212kB shmem:0kB
slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:32kB
pagetables:48kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:1824kB min:1908kB low:2384kB high:2860kB
active_anon:29452kB inactive_anon:58164kB active_file:40964kB
inactive_file:75232kB unevictable:1868kB isolated(anon):0kB
isolated(file):128kB present:243840kB mlocked:1868kB dirty:4628kB
writeback:0kB mapped:7520kB shmem:0kB slab_reclaimable:0kB
slab_unreclaimable:0kB kernel_stack:1056kB pagetables:1064kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 2*4kB 0*8kB 0*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 0*1024kB
0*2048kB 0*4096kB = 1000kB
Normal: 366*4kB 45*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 1824kB
35298 total pagecache pages
3724 pages in swap cache
Swap cache stats: add 82399, delete 78675, find 45215/53344
Free swap  = 891536kB
Total swap = 963896kB
65535 pages RAM
1236 pages reserved
36808 pages shared
32201 pages non-shared
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
skbuff alloc of size 3872 failed
logdrop IN=eth0 OUT= MAC=00:00:24:cb:ca:c4:00:01:5c:32:6e:41:08:00
SRC=219.143.125.205 DST=98.248.43.157 LEN=60 TOS=0x00 PREC=0x20 TTL=50
ID=362 DF PROTO=TCP SPT=53976 DPT=22 WINDOW=5840 RES=0x00 SYN URGP=0
OPT (020405640402080A1EDFFF550000000001030303)
__alloc_pages_slowpath: 12 callbacks suppressed
swapper: page allocation failure. order:1, mode:0x4020
Pid: 0, comm: swapper Tainted: G        W   2.6.35.4 #1
Call Trace:
 [<c0243bfe>] ? __alloc_pages_nodemask+0x3e6/0x513
 [<c025be97>] ? slob_new_pages+0xc/0x23
 [<c025c0a1>] ? __kmalloc_node+0x39/0x72
 [<c03338d8>] ? __alloc_skb+0x5c/0x105
 [<d09fa01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0ab7109>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
 [<d0ab53c5>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
 [<c02193c3>] ? tasklet_action+0x5f/0x65
 [<c0219677>] ? __do_softirq+0x60/0xc6
 [<c021970b>] ? do_softirq+0x2e/0x30
 [<c02197fd>] ? irq_exit+0x53/0x55
 [<c020392c>] ? do_IRQ+0x3a/0x72
 [<c0202be9>] ? common_interrupt+0x29/0x30
 [<c020768e>] ? default_idle+0x25/0x38
 [<c02017d0>] ? cpu_idle+0x2e/0x47
 [<c042361a>] ? start_kernel+0x21a/0x21d
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  13
active_anon:11994 inactive_anon:12762 isolated_anon:0
 active_file:13736 inactive_file:14175 isolated_file:0
 unevictable:467 dirty:5803 writeback:9 unstable:0
 free:2013 slab_reclaimable:0 slab_unreclaimable:0
 mapped:1957 shmem:0 pagetables:281 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:944kB
inactive_anon:2640kB active_file:4020kB inactive_file:4000kB
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
mlocked:0kB dirty:48kB writeback:0kB mapped:452kB shmem:0kB
slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:24kB
pagetables:24kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:7052kB min:1908kB low:2384kB high:2860kB
active_anon:47032kB inactive_anon:48408kB active_file:50924kB
inactive_file:52700kB unevictable:1868kB isolated(anon):0kB
isolated(file):0kB present:243840kB mlocked:1868kB dirty:23164kB
writeback:36kB mapped:7376kB shmem:0kB slab_reclaimable:0kB
slab_unreclaimable:0kB kernel_stack:1040kB pagetables:1100kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 2*4kB 0*8kB 0*16kB 1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 0*1024kB
0*2048kB 0*4096kB = 1000kB
Normal: 1673*4kB 45*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 7052kB
32351 total pagecache pages
4052 pages in swap cache
Swap cache stats: add 119272, delete 115220, find 58684/72663
Free swap  = 874472kB
Total swap = 963896kB
65535 pages RAM
1236 pages reserved
30733 pages shared
36511 pages non-shared
skbuff alloc of size 3872 failed
swapper: page allocation failure. order:1, mode:0x4020
Pid: 0, comm: swapper Tainted: G        W   2.6.35.4 #1
Call Trace:
 [<c0243bfe>] ? __alloc_pages_nodemask+0x3e6/0x513
 [<c025be97>] ? slob_new_pages+0xc/0x23
 [<c025c0a1>] ? __kmalloc_node+0x39/0x72
 [<c03338d8>] ? __alloc_skb+0x5c/0x105
 [<d09fa01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0ab7109>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
 [<d0ab53c5>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
 [<c02193c3>] ? tasklet_action+0x5f/0x65
 [<c0219677>] ? __do_softirq+0x60/0xc6
 [<c021970b>] ? do_softirq+0x2e/0x30
 [<c02197fd>] ? irq_exit+0x53/0x55
 [<c020392c>] ? do_IRQ+0x3a/0x72
 [<c0202be9>] ? common_interrupt+0x29/0x30
 [<c020768e>] ? default_idle+0x25/0x38
 [<c02017d0>] ? cpu_idle+0x2e/0x47
 [<c042361a>] ? start_kernel+0x21a/0x21d
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  13


2010/8/26 Nikhil Sethi (निखिल सेठी) <nikhil@sethi.ws>
>
> Thanks Eric. I have not been able to reproduce this problem after
> applying your new patch in about 12 hours of operation. Will let you
> know if the bug re-appears.
>
> Thanks
> Nikhil
>
> 2010/8/25 Eric Dumazet <eric.dumazet@gmail.com>:
> > Le mercredi 25 août 2010 à 13:25 -0700, Nikhil Sethi (निखिल सेठी) a
> > écrit :
> >> Hello.
> >>
> >> I am running 2.5.35.3 with the above patch, and I still get these
> >> failures. Though they are much less often than without the patch. A
> >> snippet from dmesg below.
> >>
> >> Please let me know what other details I should provide. Thanks
> >>
> >> skbuff alloc of size 3872 failed
> >> java: page allocation failure. order:1, mode:0x4020
> >> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
> >> Call Trace:
> >>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
> >>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
> >>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<c0334097>] ? __alloc_skb+0x57/0x100
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
> >>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
> >>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
> >>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
> >>  [<c02195bf>] ? tasklet_action+0x5f/0x65
> >>  [<c0219873>] ? __do_softirq+0x60/0xc6
> >>  [<c0219907>] ? do_softirq+0x2e/0x30
> >>  [<c02199f9>] ? irq_exit+0x53/0x55
> >>  [<c020392c>] ? do_IRQ+0x3a/0x72
> >>  [<c0202be9>] ? common_interrupt+0x29/0x30
> >> Mem-Info:
> >> DMA per-cpu:
> >> CPU    0: hi:    0, btch:   1 usd:   0
> >> Normal per-cpu:
> >> CPU    0: hi:   90, btch:  15 usd:  32
> >> active_anon:6158 inactive_anon:15748 isolated_anon:0
> >>  active_file:11477 inactive_file:22926 isolated_file:0
> >>  unevictable:468 dirty:5788 writeback:0 unstable:0
> >>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
> >>  mapped:1410 shmem:5 pagetables:227 bounce:0
> >> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
> >> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
> >> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
> >> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
> >> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
> >> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
> >> pages_scanned:0 all_unreclaimable? no
> >> lowmem_reserve[]: 0 238 238
> >> Normal free:2960kB min:1908kB low:2384kB high:2860kB
> >> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
> >> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
> >> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
> >> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
> >> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
> >> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> >> all_unreclaimable? no
> >> lowmem_reserve[]: 0 0 0
> >> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
> >> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> >> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> >> 0*1024kB 0*2048kB 0*4096kB = 2960kB
> >> 37964 total pagecache pages
> >> 3160 pages in swap cache
> >> Swap cache stats: add 164954, delete 161794, find 97931/115609
> >> Free swap  = 937284kB
> >> Total swap = 963896kB
> >> 65535 pages RAM
> >> 1237 pages reserved
> >> 29042 pages shared
> >> 38802 pages non-shared
> >> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
> >>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
> >> order: 3, min order: 1
> >>   node 0: slabs: 0, objs: 0, free: 0
> >> skbuff alloc of size 3872 failed
> >> java: page allocation failure. order:1, mode:0x4020
> >> Pid: 11464, comm: java Not tainted 2.6.35.3 #3
> >> Call Trace:
> >>  [<c0243d26>] ? __alloc_pages_nodemask+0x3e6/0x513
> >>  [<c025c293>] ? __slab_alloc+0x2d7/0x2eb
> >>  [<c025c946>] ? __kmalloc_track_caller+0x74/0x95
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<c0334097>] ? __alloc_skb+0x57/0x100
> >>  [<d09e801a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >>  [<d0af4100>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
> >>  [<d0cbc89f>] ? br_handle_frame+0x1b3/0x1c3 [bridge]
> >>  [<c033d18a>] ? __netif_receive_skb+0x141/0x25f
> >>  [<d0af23c1>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
> >>  [<c02195bf>] ? tasklet_action+0x5f/0x65
> >>  [<c0219873>] ? __do_softirq+0x60/0xc6
> >>  [<c0219907>] ? do_softirq+0x2e/0x30
> >>  [<c02199f9>] ? irq_exit+0x53/0x55
> >>  [<c020392c>] ? do_IRQ+0x3a/0x72
> >>  [<c0202be9>] ? common_interrupt+0x29/0x30
> >> Mem-Info:
> >> DMA per-cpu:
> >> CPU    0: hi:    0, btch:   1 usd:   0
> >> Normal per-cpu:
> >> CPU    0: hi:   90, btch:  15 usd:  32
> >> active_anon:6158 inactive_anon:15748 isolated_anon:0
> >>  active_file:11477 inactive_file:22926 isolated_file:0
> >>  unevictable:468 dirty:5788 writeback:0 unstable:0
> >>  free:990 slab_reclaimable:3091 slab_unreclaimable:2349
> >>  mapped:1410 shmem:5 pagetables:227 bounce:0
> >> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:1304kB
> >> inactive_anon:2304kB active_file:2584kB inactive_file:4900kB
> >> unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB
> >> mlocked:0kB dirty:0kB writeback:0kB mapped:284kB shmem:0kB
> >> slab_reclaimable:648kB slab_unreclaimable:752kB kernel_stack:152kB
> >> pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
> >> pages_scanned:0 all_unreclaimable? no
> >> lowmem_reserve[]: 0 238 238
> >> Normal free:2960kB min:1908kB low:2384kB high:2860kB
> >> active_anon:23328kB inactive_anon:60688kB active_file:43324kB
> >> inactive_file:86804kB unevictable:1872kB isolated(anon):0kB
> >> isolated(file):0kB present:243840kB mlocked:1872kB dirty:23152kB
> >> writeback:0kB mapped:5356kB shmem:20kB slab_reclaimable:11716kB
> >> slab_unreclaimable:8644kB kernel_stack:888kB pagetables:908kB
> >> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> >> all_unreclaimable? no
> >> lowmem_reserve[]: 0 0 0
> >> DMA: 76*4kB 29*8kB 5*16kB 0*32kB 0*64kB 1*128kB 1*256kB 0*512kB
> >> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> >> Normal: 650*4kB 9*8kB 2*16kB 8*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> >> 0*1024kB 0*2048kB 0*4096kB = 2960kB
> >> 37964 total pagecache pages
> >> 3160 pages in swap cache
> >>
> >> On Sun, Jun 6, 2010 at 3:42 AM, Eric Dumazet <eric.dumazet@gmail.com> wrote:
> >> >
> >> > Le dimanche 06 juin 2010 à 11:56 +0200, Michael Guntsche a écrit :
> >> > > On 2010.06.04 18:16:44 , Michael Guntsche wrote:
> >> > > > I applied the patch recompiled and run it on the routerboard, trying
> >> > > > to trigger the bug again.
> >> > >
> >> > > Hi Eric,
> >> > >
> >> > > Up to now I was not able to reproduce the bug, do you think this patch
> >> > > can be pushed to mainline or is there a "better"/other  fix for it?
> >> > >
> >> > > Kind regards,
> >> > > Michael
> >> > >
> >> > >
> >> >
> >> > Thanks Michael for testing.
> >> >
> >> > I'll submit ASAP an official patch, sent to all people involved in this
> >> > driver to get their Ack (or Nack).
> >> >
> >> > IEEE80211_MAX_MPDU_LEN being 3840 + somebits is suspect, since it doesnt
> >> > match 802.11 specs.
> >> >
> >> > It should be more close of 2304 + MAC header (32bytes) + FCS (4 bytes) ?
> >> >
> >> >
> >> >
> >> > --
> >
> >
> > reading my former patch, I believe I mistakenly used a max_t() instead
> > of a min_() macro :
> >
> > diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
> > index ca6065b..0a0dc3a 100644
> > --- a/drivers/net/wireless/ath/ath9k/recv.c
> > +++ b/drivers/net/wireless/ath/ath9k/recv.c
> > @@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
> >        u32 size;
> >
> >
> > -       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> > -                                    ah->caps.rx_status_len,
> > -                                    min(common->cachelsz, (u16)64));
> > -
> > +       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> > +                      min(common->cachelsz, (u16)64));
> > +       common->rx_bufsize = max_t(u32, size,
> > +                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
> >        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
> >                                    ah->caps.rx_status_len);
> >
> >
> >
> > Please use instead this one :
> >
> > diff --git a/drivers/net/wireless/ath/ath9k/recv.c b/drivers/net/wireless/ath/ath9k/recv.c
> > index ca6065b..0a0dc3a 100644
> > --- a/drivers/net/wireless/ath/ath9k/recv.c
> > +++ b/drivers/net/wireless/ath/ath9k/recv.c
> > @@ -226,10 +226,10 @@ static int ath_rx_edma_init(struct ath_softc *sc, int nbufs)
> >        u32 size;
> >
> >
> > -       common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> > -                                    ah->caps.rx_status_len,
> > -                                    min(common->cachelsz, (u16)64));
> > -
> > +       size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> > +                      min(common->cachelsz, (u16)64));
> > +       common->rx_bufsize = min_t(u32, size,
> > +                                  SKB_MAX_ORDER(NET_SKB_PAD + common->cachelsz, 0));
> >        ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
> >                                    ah->caps.rx_status_len);
> >
> >
> >
> >
> >

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Eric Dumazet]

Le dimanche 05 septembre 2010 à 08:51 -0700, Nikhil Sethi (निखिल सेठी) a
écrit :
> This came back. Here is the dmesg output. It might be the problem only
> happens if I have wmm_enabled=1 in my hostapd.conf. That is the only
> thing that I changed yesterday, and today I saw these messages in my
> logs. I will try to conform this.
> 
> 
> I am running 2.6.35.4 with this patch:
> 
> 
> *** 225,234 ****
>    int error = 0, i;
>    u32 size;
>   
> ! 
> ! common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> !     ah->caps.rx_status_len,
> !     min(common->cachelsz, (u16)64));
>   
>    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
>       ah->caps.rx_status_len);
> --- 225,234 ----
>    int error = 0, i;
>    u32 size;
>   
> ! size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> !                        min(common->cachelsz, (u16)64));
> !         common->rx_bufsize = min_t(u32, size,
> !                                    SKB_MAX_ORDER(NET_SKB_PAD +
> common->cachelsz, 0));
>   
>    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
>       ah->caps.rx_status_len);
> 
> 
> dmesg output:
> 
> 
> skbuff alloc of size 3872 failed
> ps: page allocation failure. order:1, mode:0x4020
> Pid: 16022, comm: ps Tainted: G        W   2.6.35.4 #1
> Call Trace:
>  [<c0243bfe>] ? __alloc_pages_nodemask+0x3e6/0x513
>  [<c025be97>] ? slob_new_pages+0xc/0x23

Unfortunately you use SLOB, and it seems to ask order-1 pages, while
we want less than a page.

Please try SLAB or SLUB

>  [<c025c0a1>] ? __kmalloc_node+0x39/0x72
>  [<c03338d8>] ? __alloc_skb+0x5c/0x105
>  [<d09fa01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d0ab7109>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
>  [<c030fd49>] ? scsi_next_command+0x27/0x34
>  [<d0ab53c5>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
>  [<c02193c3>] ? tasklet_action+0x5f/0x65
>  [<c0219677>] ? __do_softirq+0x60/0xc6
>  [<c021970b>] ? do_softirq+0x2e/0x30
>  [<c02197fd>] ? irq_exit+0x53/0x55
>  [<c020392c>] ? do_IRQ+0x3a/0x72
>  [<c0202be9>] ? common_interrupt+0x29/0x30
>  [<c0247874>] ? __remove_mapping+0x4b/0x8d
>  [<c023ea9f>] ? try_to_release_page+0x20/0x30
>  [<c0247d36>] ? shrink_page_list+0x2b8/0x46c
>  [<c03158ea>] ? sd_prep_fn+0x1a5/0x92b
>  [<c024816b>] ? shrink_inactive_list+0x281/0x552
>  [<c02445d9>] ? determine_dirtyable_memory+0xc/0x12
>  [<c024462c>] ? get_dirty_limits+0x18/0x2b0
>  [<c032875e>] ? ata_bmdma_port_intr+0x21/0xcd
>  [<c0248683>] ? shrink_zone+0x247/0x38f
>  [<c021968c>] ? __do_softirq+0x75/0xc6
>  [<c0247114>] ? shrink_slab+0x13c/0x186
>  [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
>  [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
>  [<c0243acf>] ? __alloc_pages_nodemask+0x2b7/0x513
>  [<c025be97>] ? slob_new_pages+0xc/0x23
>  [<c025c038>] ? kmem_cache_alloc_node+0x23/0x53
>  [<c0264b20>] ? getname+0x19/0xae
>  [<c0266d00>] ? user_path_at+0x11/0x64
>  [<c0250949>] ? access_process_vm+0xe0/0x1e7
>  [<c0250a08>] ? access_process_vm+0x19f/0x1e7
>  [<c02603d2>] ? vfs_fstatat+0x25/0x63
>  [<c02604a9>] ? vfs_stat+0x10/0x12
>  [<c02604ba>] ? sys_stat64+0xf/0x23
>  [<c025e86b>] ? fput+0x88/0x191
>  [<c026ab3b>] ? dput+0x92/0xd4
>  [<c025e8ff>] ? fput+0x11c/0x191
>  [<c026ebec>] ? mntput_no_expire+0x13/0x60
>  [<c025c398>] ? filp_close+0x3b/0x54
>  [<c025c403>] ? sys_close+0x52/0x72
>  [<c038ad3d>] ? syscall_call+0x7/0xb
>  [<c0380000>] ? unix_dgram_sendmsg+0x258/0x3c1
> Mem-Info:

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Nikhil Sethi (निखिल सेठी)]

Thanks Eric, for all the help.
I get very occasional errors with vanilla 2.6.36 kernel with your
patch. Error messages are slightly different, and very rare compared
to without your patch. 2.6.35.7 seems fine, and does not show this
error.

rsync: page allocation failure. order:1, mode:0x4020
Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
Call Trace:
 [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
 [<c0261330>] ? __slab_alloc+0x40f/0x45a
 [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<c033a8d0>] ? __alloc_skb+0x57/0x100
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
 [<c02234ae>] ? __queue_work+0xe4/0x1a2
 [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
 [<c0219a43>] ? tasklet_action+0x5f/0x65
 [<c0219cf4>] ? __do_softirq+0x60/0xc6
 [<c0219d88>] ? do_softirq+0x2e/0x30
 [<c0219e7b>] ? irq_exit+0x54/0x56
 [<c02038e0>] ? do_IRQ+0x3a/0x72
 [<c0202bc9>] ? common_interrupt+0x29/0x30
 [<c02d89a0>] ? cfq_may_queue+0x0/0x92
 [<c02d1567>] ? get_request+0x121/0x23e
 [<c02d16a4>] ? get_request_wait+0x20/0xfd
 [<c02d8f16>] ? cfq_merge+0x0/0x69
 [<c02cfd40>] ? elv_merge+0x14b/0x170
 [<c02d2375>] ? __make_request+0x71/0x364
 [<c02d1fe2>] ? generic_make_request+0x14f/0x318
 [<c0243fb1>] ? mempool_alloc+0x35/0xb9
 [<c02d21e9>] ? submit_bio+0x3e/0x90
 [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
 [<c027e780>] ? submit_bh+0xbc/0xec
 [<c027f4e2>] ? ll_rw_block+0x72/0x74
 [<c027f504>] ? __breadahead+0x20/0x30
 [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
 [<c02a8154>] ? ext4_iget+0x52/0x652
 [<c02aa327>] ? ext4_lookup+0x65/0xbf
 [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
 [<c026b84a>] ? do_lookup+0xc5/0xfe
 [<c026c239>] ? link_path_walk+0x4d1/0x8d6
 [<c026c722>] ? path_walk+0x48/0xa9
 [<c026c7be>] ? do_path_lookup+0x3b/0x3f
 [<c026d06d>] ? user_path_at+0x30/0x64
 [<c0266446>] ? cp_new_stat64+0xee/0x100
 [<c026664a>] ? vfs_fstatat+0x25/0x63
 [<c02666c9>] ? vfs_lstat+0x13/0x15
 [<c02666da>] ? sys_lstat64+0xf/0x23
 [<c02141ed>] ? switched_to_idle+0x1a/0x43
 [<c0393395>] ? syscall_call+0x7/0xb
 [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  84
active_anon:14957 inactive_anon:15137 isolated_anon:0
 active_file:11820 inactive_file:11640 isolated_file:0
 unevictable:470 dirty:1378 writeback:0 unstable:0
 free:975 slab_reclaimable:5606 slab_unreclaimable:2343
 mapped:2786 shmem:72 pagetables:394 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
unevictable:348kB isolated(anon):0kB isolated(file):0kB
present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:2900kB min:1908kB low:2384kB high:2860kB
active_anon:56932kB inactive_anon:56996kB active_file:45164kB
inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
0*1024kB 0*2048kB 0*4096kB = 1000kB
Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 2900kB
28310 total pagecache pages
4385 pages in swap cache
Swap cache stats: add 144387, delete 140002, find 98398/115667
Free swap  = 889116kB
Total swap = 1023996kB
65535 pages RAM
1245 pages reserved
27369 pages shared
42219 pages non-shared
SLUB: Unable to allocate memory on node -1 (gfp=0x20)
  cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
order: 3, min order: 1
  node 0: slabs: 133, objs: 529, free: 0
skbuff alloc of size 3872 failed
rsync: page allocation failure. order:1, mode:0x4020
Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
Call Trace:
 [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
 [<c0261330>] ? __slab_alloc+0x40f/0x45a
 [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<c033a8d0>] ? __alloc_skb+0x57/0x100
 [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
 [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
 [<c02234ae>] ? __queue_work+0xe4/0x1a2
 [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
 [<c0219a43>] ? tasklet_action+0x5f/0x65
 [<c0219cf4>] ? __do_softirq+0x60/0xc6
 [<c0219d88>] ? do_softirq+0x2e/0x30
 [<c0219e7b>] ? irq_exit+0x54/0x56
 [<c02038e0>] ? do_IRQ+0x3a/0x72
 [<c0202bc9>] ? common_interrupt+0x29/0x30
 [<c02d89a0>] ? cfq_may_queue+0x0/0x92
 [<c02d1567>] ? get_request+0x121/0x23e
 [<c02d16a4>] ? get_request_wait+0x20/0xfd
 [<c02d8f16>] ? cfq_merge+0x0/0x69
 [<c02cfd40>] ? elv_merge+0x14b/0x170
 [<c02d2375>] ? __make_request+0x71/0x364
 [<c02d1fe2>] ? generic_make_request+0x14f/0x318
 [<c0243fb1>] ? mempool_alloc+0x35/0xb9
 [<c02d21e9>] ? submit_bio+0x3e/0x90
 [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
 [<c027e780>] ? submit_bh+0xbc/0xec
 [<c027f4e2>] ? ll_rw_block+0x72/0x74
 [<c027f504>] ? __breadahead+0x20/0x30
 [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
 [<c02a8154>] ? ext4_iget+0x52/0x652
 [<c02aa327>] ? ext4_lookup+0x65/0xbf
 [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
 [<c026b84a>] ? do_lookup+0xc5/0xfe
 [<c026c239>] ? link_path_walk+0x4d1/0x8d6
 [<c026c722>] ? path_walk+0x48/0xa9
 [<c026c7be>] ? do_path_lookup+0x3b/0x3f
 [<c026d06d>] ? user_path_at+0x30/0x64
 [<c0266446>] ? cp_new_stat64+0xee/0x100
 [<c026664a>] ? vfs_fstatat+0x25/0x63
 [<c02666c9>] ? vfs_lstat+0x13/0x15
 [<c02666da>] ? sys_lstat64+0xf/0x23
 [<c02141ed>] ? switched_to_idle+0x1a/0x43
 [<c0393395>] ? syscall_call+0x7/0xb
 [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
Mem-Info:
DMA per-cpu:
CPU    0: hi:    0, btch:   1 usd:   0
Normal per-cpu:
CPU    0: hi:   90, btch:  15 usd:  84
active_anon:14957 inactive_anon:15137 isolated_anon:0
 active_file:11820 inactive_file:11640 isolated_file:0
 unevictable:470 dirty:1378 writeback:0 unstable:0
 free:975 slab_reclaimable:5606 slab_unreclaimable:2343
 mapped:2786 shmem:72 pagetables:394 bounce:0
DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
unevictable:348kB isolated(anon):0kB isolated(file):0kB
present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
lowmem_reserve[]: 0 238 238
Normal free:2900kB min:1908kB low:2384kB high:2860kB
active_anon:56932kB inactive_anon:56996kB active_file:45164kB
inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
0*1024kB 0*2048kB 0*4096kB = 1000kB
Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 2900kB
28310 total pagecache pages
4385 pages in swap cache
Swap cache stats: add 144387, delete 140002, find 98398/115667
Free swap  = 889116kB
Total swap = 1023996kB
65535 pages RAM
1245 pages reserved
27369 pages shared
42219 pages non-shared
SLUB: Unable to allocate memory on node -1 (gfp=0x20)
  cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
order: 3, min order: 1
  node 0: slabs: 133, objs: 529, free: 0
skbuff alloc of size 3872 failed

2010/9/5 Eric Dumazet <eric.dumazet@gmail.com>
>
> Le dimanche 05 septembre 2010 à 08:51 -0700, Nikhil Sethi (निखिल सेठी) a
> écrit :
> > This came back. Here is the dmesg output. It might be the problem only
> > happens if I have wmm_enabled=1 in my hostapd.conf. That is the only
> > thing that I changed yesterday, and today I saw these messages in my
> > logs. I will try to conform this.
> >
> >
> > I am running 2.6.35.4 with this patch:
> >
> >
> > *** 225,234 ****
> >    int error = 0, i;
> >    u32 size;
> >
> > !
> > ! common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> > !     ah->caps.rx_status_len,
> > !     min(common->cachelsz, (u16)64));
> >
> >    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
> >       ah->caps.rx_status_len);
> > --- 225,234 ----
> >    int error = 0, i;
> >    u32 size;
> >
> > ! size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> > !                        min(common->cachelsz, (u16)64));
> > !         common->rx_bufsize = min_t(u32, size,
> > !                                    SKB_MAX_ORDER(NET_SKB_PAD +
> > common->cachelsz, 0));
> >
> >    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
> >       ah->caps.rx_status_len);
> >
> >
> > dmesg output:
> >
> >
> > skbuff alloc of size 3872 failed
> > ps: page allocation failure. order:1, mode:0x4020
> > Pid: 16022, comm: ps Tainted: G        W   2.6.35.4 #1
> > Call Trace:
> >  [<c0243bfe>] ? __alloc_pages_nodemask+0x3e6/0x513
> >  [<c025be97>] ? slob_new_pages+0xc/0x23
>
> Unfortunately you use SLOB, and it seems to ask order-1 pages, while
> we want less than a page.
>
> Please try SLAB or SLUB
>
> >  [<c025c0a1>] ? __kmalloc_node+0x39/0x72
> >  [<c03338d8>] ? __alloc_skb+0x5c/0x105
> >  [<d09fa01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
> >  [<d0ab7109>] ? ath_rx_tasklet+0x2fb/0x808 [ath9k]
> >  [<c030fd49>] ? scsi_next_command+0x27/0x34
> >  [<d0ab53c5>] ? ath9k_tasklet+0xcc/0x107 [ath9k]
> >  [<c02193c3>] ? tasklet_action+0x5f/0x65
> >  [<c0219677>] ? __do_softirq+0x60/0xc6
> >  [<c021970b>] ? do_softirq+0x2e/0x30
> >  [<c02197fd>] ? irq_exit+0x53/0x55
> >  [<c020392c>] ? do_IRQ+0x3a/0x72
> >  [<c0202be9>] ? common_interrupt+0x29/0x30
> >  [<c0247874>] ? __remove_mapping+0x4b/0x8d
> >  [<c023ea9f>] ? try_to_release_page+0x20/0x30
> >  [<c0247d36>] ? shrink_page_list+0x2b8/0x46c
> >  [<c03158ea>] ? sd_prep_fn+0x1a5/0x92b
> >  [<c024816b>] ? shrink_inactive_list+0x281/0x552
> >  [<c02445d9>] ? determine_dirtyable_memory+0xc/0x12
> >  [<c024462c>] ? get_dirty_limits+0x18/0x2b0
> >  [<c032875e>] ? ata_bmdma_port_intr+0x21/0xcd
> >  [<c0248683>] ? shrink_zone+0x247/0x38f
> >  [<c021968c>] ? __do_softirq+0x75/0xc6
> >  [<c0247114>] ? shrink_slab+0x13c/0x186
> >  [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
> >  [<c0248f25>] ? try_to_free_pages+0x1ab/0x2be
> >  [<c0243acf>] ? __alloc_pages_nodemask+0x2b7/0x513
> >  [<c025be97>] ? slob_new_pages+0xc/0x23
> >  [<c025c038>] ? kmem_cache_alloc_node+0x23/0x53
> >  [<c0264b20>] ? getname+0x19/0xae
> >  [<c0266d00>] ? user_path_at+0x11/0x64
> >  [<c0250949>] ? access_process_vm+0xe0/0x1e7
> >  [<c0250a08>] ? access_process_vm+0x19f/0x1e7
> >  [<c02603d2>] ? vfs_fstatat+0x25/0x63
> >  [<c02604a9>] ? vfs_stat+0x10/0x12
> >  [<c02604ba>] ? sys_stat64+0xf/0x23
> >  [<c025e86b>] ? fput+0x88/0x191
> >  [<c026ab3b>] ? dput+0x92/0xd4
> >  [<c025e8ff>] ? fput+0x11c/0x191
> >  [<c026ebec>] ? mntput_no_expire+0x13/0x60
> >  [<c025c398>] ? filp_close+0x3b/0x54
> >  [<c025c403>] ? sys_close+0x52/0x72
> >  [<c038ad3d>] ? syscall_call+0x7/0xb
> >  [<c0380000>] ? unix_dgram_sendmsg+0x258/0x3c1
> > Mem-Info:
>
>
>

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Eric Dumazet]

Le lundi 08 novembre 2010 à 08:25 -0800, Nikhil Sethi (निखिल सेठी) a
écrit :
> Thanks Eric, for all the help.
> I get very occasional errors with vanilla 2.6.36 kernel with your
> patch. Error messages are slightly different, and very rare compared
> to without your patch. 2.6.35.7 seems fine, and does not show this
> error.
> 
> rsync: page allocation failure. order:1, mode:0x4020
> Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
> Call Trace:
>  [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
>  [<c0261330>] ? __slab_alloc+0x40f/0x45a
>  [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<c033a8d0>] ? __alloc_skb+0x57/0x100
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
>  [<c02234ae>] ? __queue_work+0xe4/0x1a2
>  [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
>  [<c0219a43>] ? tasklet_action+0x5f/0x65
>  [<c0219cf4>] ? __do_softirq+0x60/0xc6
>  [<c0219d88>] ? do_softirq+0x2e/0x30
>  [<c0219e7b>] ? irq_exit+0x54/0x56
>  [<c02038e0>] ? do_IRQ+0x3a/0x72
>  [<c0202bc9>] ? common_interrupt+0x29/0x30
>  [<c02d89a0>] ? cfq_may_queue+0x0/0x92
>  [<c02d1567>] ? get_request+0x121/0x23e
>  [<c02d16a4>] ? get_request_wait+0x20/0xfd
>  [<c02d8f16>] ? cfq_merge+0x0/0x69
>  [<c02cfd40>] ? elv_merge+0x14b/0x170
>  [<c02d2375>] ? __make_request+0x71/0x364
>  [<c02d1fe2>] ? generic_make_request+0x14f/0x318
>  [<c0243fb1>] ? mempool_alloc+0x35/0xb9
>  [<c02d21e9>] ? submit_bio+0x3e/0x90
>  [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
>  [<c027e780>] ? submit_bh+0xbc/0xec
>  [<c027f4e2>] ? ll_rw_block+0x72/0x74
>  [<c027f504>] ? __breadahead+0x20/0x30
>  [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
>  [<c02a8154>] ? ext4_iget+0x52/0x652
>  [<c02aa327>] ? ext4_lookup+0x65/0xbf
>  [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
>  [<c026b84a>] ? do_lookup+0xc5/0xfe
>  [<c026c239>] ? link_path_walk+0x4d1/0x8d6
>  [<c026c722>] ? path_walk+0x48/0xa9
>  [<c026c7be>] ? do_path_lookup+0x3b/0x3f
>  [<c026d06d>] ? user_path_at+0x30/0x64
>  [<c0266446>] ? cp_new_stat64+0xee/0x100
>  [<c026664a>] ? vfs_fstatat+0x25/0x63
>  [<c02666c9>] ? vfs_lstat+0x13/0x15
>  [<c02666da>] ? sys_lstat64+0xf/0x23
>  [<c02141ed>] ? switched_to_idle+0x1a/0x43
>  [<c0393395>] ? syscall_call+0x7/0xb
>  [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
> Mem-Info:
> DMA per-cpu:
> CPU    0: hi:    0, btch:   1 usd:   0
> Normal per-cpu:
> CPU    0: hi:   90, btch:  15 usd:  84
> active_anon:14957 inactive_anon:15137 isolated_anon:0
>  active_file:11820 inactive_file:11640 isolated_file:0
>  unevictable:470 dirty:1378 writeback:0 unstable:0
>  free:975 slab_reclaimable:5606 slab_unreclaimable:2343
>  mapped:2786 shmem:72 pagetables:394 bounce:0
> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
> inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
> unevictable:348kB isolated(anon):0kB isolated(file):0kB
> present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
> shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
> kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
> writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
> lowmem_reserve[]: 0 238 238
> Normal free:2900kB min:1908kB low:2384kB high:2860kB
> active_anon:56932kB inactive_anon:56996kB active_file:45164kB
> inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
> isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
> writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
> slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> lowmem_reserve[]: 0 0 0
> DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 2900kB
> 28310 total pagecache pages
> 4385 pages in swap cache
> Swap cache stats: add 144387, delete 140002, find 98398/115667
> Free swap  = 889116kB
> Total swap = 1023996kB
> 65535 pages RAM
> 1245 pages reserved
> 27369 pages shared
> 42219 pages non-shared
> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
> order: 3, min order: 1
>   node 0: slabs: 133, objs: 529, free: 0
> skbuff alloc of size 3872 failed
> rsync: page allocation failure. order:1, mode:0x4020
> Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
> Call Trace:
>  [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
>  [<c0261330>] ? __slab_alloc+0x40f/0x45a
>  [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<c033a8d0>] ? __alloc_skb+0x57/0x100
>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>  [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
>  [<c02234ae>] ? __queue_work+0xe4/0x1a2
>  [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
>  [<c0219a43>] ? tasklet_action+0x5f/0x65
>  [<c0219cf4>] ? __do_softirq+0x60/0xc6
>  [<c0219d88>] ? do_softirq+0x2e/0x30
>  [<c0219e7b>] ? irq_exit+0x54/0x56
>  [<c02038e0>] ? do_IRQ+0x3a/0x72
>  [<c0202bc9>] ? common_interrupt+0x29/0x30
>  [<c02d89a0>] ? cfq_may_queue+0x0/0x92
>  [<c02d1567>] ? get_request+0x121/0x23e
>  [<c02d16a4>] ? get_request_wait+0x20/0xfd
>  [<c02d8f16>] ? cfq_merge+0x0/0x69
>  [<c02cfd40>] ? elv_merge+0x14b/0x170
>  [<c02d2375>] ? __make_request+0x71/0x364
>  [<c02d1fe2>] ? generic_make_request+0x14f/0x318
>  [<c0243fb1>] ? mempool_alloc+0x35/0xb9
>  [<c02d21e9>] ? submit_bio+0x3e/0x90
>  [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
>  [<c027e780>] ? submit_bh+0xbc/0xec
>  [<c027f4e2>] ? ll_rw_block+0x72/0x74
>  [<c027f504>] ? __breadahead+0x20/0x30
>  [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
>  [<c02a8154>] ? ext4_iget+0x52/0x652
>  [<c02aa327>] ? ext4_lookup+0x65/0xbf
>  [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
>  [<c026b84a>] ? do_lookup+0xc5/0xfe
>  [<c026c239>] ? link_path_walk+0x4d1/0x8d6
>  [<c026c722>] ? path_walk+0x48/0xa9
>  [<c026c7be>] ? do_path_lookup+0x3b/0x3f
>  [<c026d06d>] ? user_path_at+0x30/0x64
>  [<c0266446>] ? cp_new_stat64+0xee/0x100
>  [<c026664a>] ? vfs_fstatat+0x25/0x63
>  [<c02666c9>] ? vfs_lstat+0x13/0x15
>  [<c02666da>] ? sys_lstat64+0xf/0x23
>  [<c02141ed>] ? switched_to_idle+0x1a/0x43
>  [<c0393395>] ? syscall_call+0x7/0xb
>  [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
> Mem-Info:
> DMA per-cpu:
> CPU    0: hi:    0, btch:   1 usd:   0
> Normal per-cpu:
> CPU    0: hi:   90, btch:  15 usd:  84
> active_anon:14957 inactive_anon:15137 isolated_anon:0
>  active_file:11820 inactive_file:11640 isolated_file:0
>  unevictable:470 dirty:1378 writeback:0 unstable:0
>  free:975 slab_reclaimable:5606 slab_unreclaimable:2343
>  mapped:2786 shmem:72 pagetables:394 bounce:0
> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
> inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
> unevictable:348kB isolated(anon):0kB isolated(file):0kB
> present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
> shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
> kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
> writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
> lowmem_reserve[]: 0 238 238
> Normal free:2900kB min:1908kB low:2384kB high:2860kB
> active_anon:56932kB inactive_anon:56996kB active_file:45164kB
> inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
> isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
> writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
> slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> lowmem_reserve[]: 0 0 0
> DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
> 0*1024kB 0*2048kB 0*4096kB = 1000kB
> Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 2900kB
> 28310 total pagecache pages
> 4385 pages in swap cache
> Swap cache stats: add 144387, delete 140002, find 98398/115667
> Free swap  = 889116kB
> Total swap = 1023996kB
> 65535 pages RAM
> 1245 pages reserved
> 27369 pages shared
> 42219 pages non-shared
> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
> order: 3, min order: 1
>   node 0: slabs: 133, objs: 529, free: 0
> skbuff alloc of size 3872 failed
> 
> 2010/9/5 Eric Dumazet <eric.dumazet@gmail.com>
> >
> > Le dimanche 05 septembre 2010 à 08:51 -0700, Nikhil Sethi (निखिल सेठी) a
> > écrit :
> > > This came back. Here is the dmesg output. It might be the problem only
> > > happens if I have wmm_enabled=1 in my hostapd.conf. That is the only
> > > thing that I changed yesterday, and today I saw these messages in my
> > > logs. I will try to conform this.
> > >
> > >
> > > I am running 2.6.35.4 with this patch:
> > >
> > >
> > > *** 225,234 ****
> > >    int error = 0, i;
> > >    u32 size;
> > >
> > > !
> > > ! common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
> > > !     ah->caps.rx_status_len,
> > > !     min(common->cachelsz, (u16)64));
> > >
> > >    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
> > >       ah->caps.rx_status_len);
> > > --- 225,234 ----
> > >    int error = 0, i;
> > >    u32 size;
> > >
> > > ! size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
> > > !                        min(common->cachelsz, (u16)64));
> > > !         common->rx_bufsize = min_t(u32, size,
> > > !                                    SKB_MAX_ORDER(NET_SKB_PAD +
> > > common->cachelsz, 0));


Its very hard to follow this thread, with a message every two months.


As I said, this patch got a min_t() instead of max_t()

http://kerneltrap.org/mailarchive/linux-kernel/2010/8/25/4611322

If you still have kmalloc-8192 allocations, I suspect you dont use right
patch.

Re: [2.6.35-rc1] page alloc failure order:1, mode:0x4020

[Nikhil Sethi (निखिल सेठी)]

As I said, this seems like a regression in 2.6.36 from 2.6.35 (which
is why I emailed after 2 months :) ). You mentioned earlier in the
thread that you were going to submit the patch to head, if there is a
separate bug/thread tracking that, I can send followups to that.

I believe I have the right patch:

*** 225,234 ****
  	int error = 0, i;
  	u32 size;

!
! 	common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
! 				     ah->caps.rx_status_len,
! 				     min(common->cachelsz, (u16)64));

  	ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
  				    ah->caps.rx_status_len);
--- 225,234 ----
  	int error = 0, i;
  	u32 size;

! 	size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
!                        min(common->cachelsz, (u16)64));
!         common->rx_bufsize = min_t(u32, size,
!                                    SKB_MAX_ORDER(NET_SKB_PAD +
common->cachelsz, 0));

  	ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
  				    ah->caps.rx_status_len);


2010/11/8 Eric Dumazet <eric.dumazet@gmail.com>:
> Le lundi 08 novembre 2010 à 08:25 -0800, Nikhil Sethi (निखिल सेठी) a
> écrit :
>> Thanks Eric, for all the help.
>> I get very occasional errors with vanilla 2.6.36 kernel with your
>> patch. Error messages are slightly different, and very rare compared
>> to without your patch. 2.6.35.7 seems fine, and does not show this
>> error.
>>
>> rsync: page allocation failure. order:1, mode:0x4020
>> Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
>> Call Trace:
>>  [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
>>  [<c0261330>] ? __slab_alloc+0x40f/0x45a
>>  [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<c033a8d0>] ? __alloc_skb+0x57/0x100
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
>>  [<c02234ae>] ? __queue_work+0xe4/0x1a2
>>  [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
>>  [<c0219a43>] ? tasklet_action+0x5f/0x65
>>  [<c0219cf4>] ? __do_softirq+0x60/0xc6
>>  [<c0219d88>] ? do_softirq+0x2e/0x30
>>  [<c0219e7b>] ? irq_exit+0x54/0x56
>>  [<c02038e0>] ? do_IRQ+0x3a/0x72
>>  [<c0202bc9>] ? common_interrupt+0x29/0x30
>>  [<c02d89a0>] ? cfq_may_queue+0x0/0x92
>>  [<c02d1567>] ? get_request+0x121/0x23e
>>  [<c02d16a4>] ? get_request_wait+0x20/0xfd
>>  [<c02d8f16>] ? cfq_merge+0x0/0x69
>>  [<c02cfd40>] ? elv_merge+0x14b/0x170
>>  [<c02d2375>] ? __make_request+0x71/0x364
>>  [<c02d1fe2>] ? generic_make_request+0x14f/0x318
>>  [<c0243fb1>] ? mempool_alloc+0x35/0xb9
>>  [<c02d21e9>] ? submit_bio+0x3e/0x90
>>  [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
>>  [<c027e780>] ? submit_bh+0xbc/0xec
>>  [<c027f4e2>] ? ll_rw_block+0x72/0x74
>>  [<c027f504>] ? __breadahead+0x20/0x30
>>  [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
>>  [<c02a8154>] ? ext4_iget+0x52/0x652
>>  [<c02aa327>] ? ext4_lookup+0x65/0xbf
>>  [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
>>  [<c026b84a>] ? do_lookup+0xc5/0xfe
>>  [<c026c239>] ? link_path_walk+0x4d1/0x8d6
>>  [<c026c722>] ? path_walk+0x48/0xa9
>>  [<c026c7be>] ? do_path_lookup+0x3b/0x3f
>>  [<c026d06d>] ? user_path_at+0x30/0x64
>>  [<c0266446>] ? cp_new_stat64+0xee/0x100
>>  [<c026664a>] ? vfs_fstatat+0x25/0x63
>>  [<c02666c9>] ? vfs_lstat+0x13/0x15
>>  [<c02666da>] ? sys_lstat64+0xf/0x23
>>  [<c02141ed>] ? switched_to_idle+0x1a/0x43
>>  [<c0393395>] ? syscall_call+0x7/0xb
>>  [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
>> Mem-Info:
>> DMA per-cpu:
>> CPU    0: hi:    0, btch:   1 usd:   0
>> Normal per-cpu:
>> CPU    0: hi:   90, btch:  15 usd:  84
>> active_anon:14957 inactive_anon:15137 isolated_anon:0
>>  active_file:11820 inactive_file:11640 isolated_file:0
>>  unevictable:470 dirty:1378 writeback:0 unstable:0
>>  free:975 slab_reclaimable:5606 slab_unreclaimable:2343
>>  mapped:2786 shmem:72 pagetables:394 bounce:0
>> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
>> inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
>> unevictable:348kB isolated(anon):0kB isolated(file):0kB
>> present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
>> shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
>> kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
>> writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
>> lowmem_reserve[]: 0 238 238
>> Normal free:2900kB min:1908kB low:2384kB high:2860kB
>> active_anon:56932kB inactive_anon:56996kB active_file:45164kB
>> inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
>> isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
>> writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
>> slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
>> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
>> all_unreclaimable? no
>> lowmem_reserve[]: 0 0 0
>> DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 1000kB
>> Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 2900kB
>> 28310 total pagecache pages
>> 4385 pages in swap cache
>> Swap cache stats: add 144387, delete 140002, find 98398/115667
>> Free swap  = 889116kB
>> Total swap = 1023996kB
>> 65535 pages RAM
>> 1245 pages reserved
>> 27369 pages shared
>> 42219 pages non-shared
>> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
>> order: 3, min order: 1
>>   node 0: slabs: 133, objs: 529, free: 0
>> skbuff alloc of size 3872 failed
>> rsync: page allocation failure. order:1, mode:0x4020
>> Pid: 31479, comm: rsync Not tainted 2.6.36-rc1 #1
>> Call Trace:
>>  [<c0246b2c>] ? __alloc_pages_nodemask+0x3f1/0x52e
>>  [<c0261330>] ? __slab_alloc+0x40f/0x45a
>>  [<c02617ca>] ? __kmalloc_track_caller+0x91/0x97
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<c033a8d0>] ? __alloc_skb+0x57/0x100
>>  [<d09db01a>] ? ath_rxbuf_alloc+0x1a/0x78 [ath]
>>  [<d0b01f2e>] ? ath_rx_tasklet+0x680/0xcfe [ath9k]
>>  [<c02234ae>] ? __queue_work+0xe4/0x1a2
>>  [<d0b00244>] ? ath9k_tasklet+0xd0/0x134 [ath9k]
>>  [<c0219a43>] ? tasklet_action+0x5f/0x65
>>  [<c0219cf4>] ? __do_softirq+0x60/0xc6
>>  [<c0219d88>] ? do_softirq+0x2e/0x30
>>  [<c0219e7b>] ? irq_exit+0x54/0x56
>>  [<c02038e0>] ? do_IRQ+0x3a/0x72
>>  [<c0202bc9>] ? common_interrupt+0x29/0x30
>>  [<c02d89a0>] ? cfq_may_queue+0x0/0x92
>>  [<c02d1567>] ? get_request+0x121/0x23e
>>  [<c02d16a4>] ? get_request_wait+0x20/0xfd
>>  [<c02d8f16>] ? cfq_merge+0x0/0x69
>>  [<c02cfd40>] ? elv_merge+0x14b/0x170
>>  [<c02d2375>] ? __make_request+0x71/0x364
>>  [<c02d1fe2>] ? generic_make_request+0x14f/0x318
>>  [<c0243fb1>] ? mempool_alloc+0x35/0xb9
>>  [<c02d21e9>] ? submit_bio+0x3e/0x90
>>  [<c0281c14>] ? bio_alloc_bioset+0x33/0x9e
>>  [<c027e780>] ? submit_bh+0xbc/0xec
>>  [<c027f4e2>] ? ll_rw_block+0x72/0x74
>>  [<c027f504>] ? __breadahead+0x20/0x30
>>  [<c02a3a8f>] ? __ext4_get_inode_loc+0x308/0x416
>>  [<c02a8154>] ? ext4_iget+0x52/0x652
>>  [<c02aa327>] ? ext4_lookup+0x65/0xbf
>>  [<c026a6bb>] ? d_alloc_and_lookup+0x30/0x58
>>  [<c026b84a>] ? do_lookup+0xc5/0xfe
>>  [<c026c239>] ? link_path_walk+0x4d1/0x8d6
>>  [<c026c722>] ? path_walk+0x48/0xa9
>>  [<c026c7be>] ? do_path_lookup+0x3b/0x3f
>>  [<c026d06d>] ? user_path_at+0x30/0x64
>>  [<c0266446>] ? cp_new_stat64+0xee/0x100
>>  [<c026664a>] ? vfs_fstatat+0x25/0x63
>>  [<c02666c9>] ? vfs_lstat+0x13/0x15
>>  [<c02666da>] ? sys_lstat64+0xf/0x23
>>  [<c02141ed>] ? switched_to_idle+0x1a/0x43
>>  [<c0393395>] ? syscall_call+0x7/0xb
>>  [<c0390000>] ? quirk_ich7_lpc+0x46/0x4d
>> Mem-Info:
>> DMA per-cpu:
>> CPU    0: hi:    0, btch:   1 usd:   0
>> Normal per-cpu:
>> CPU    0: hi:   90, btch:  15 usd:  84
>> active_anon:14957 inactive_anon:15137 isolated_anon:0
>>  active_file:11820 inactive_file:11640 isolated_file:0
>>  unevictable:470 dirty:1378 writeback:0 unstable:0
>>  free:975 slab_reclaimable:5606 slab_unreclaimable:2343
>>  mapped:2786 shmem:72 pagetables:394 bounce:0
>> DMA free:1000kB min:124kB low:152kB high:184kB active_anon:2896kB
>> inactive_anon:3552kB active_file:2116kB inactive_file:1768kB
>> unevictable:348kB isolated(anon):0kB isolated(file):0kB
>> present:15864kB mlocked:348kB dirty:16kB writeback:0kB mapped:228kB
>> shmem:32kB slab_reclaimable:1136kB slab_unreclaimable:608kB
>> kernel_stack:144kB pagetables:52kB unstable:0kB bounce:0kB
>> writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
>> lowmem_reserve[]: 0 238 238
>> Normal free:2900kB min:1908kB low:2384kB high:2860kB
>> active_anon:56932kB inactive_anon:56996kB active_file:45164kB
>> inactive_file:44792kB unevictable:1532kB isolated(anon):0kB
>> isolated(file):0kB present:243840kB mlocked:1532kB dirty:5496kB
>> writeback:0kB mapped:10916kB shmem:256kB slab_reclaimable:21288kB
>> slab_unreclaimable:8764kB kernel_stack:1056kB pagetables:1524kB
>> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
>> all_unreclaimable? no
>> lowmem_reserve[]: 0 0 0
>> DMA: 6*4kB 14*8kB 16*16kB 1*32kB 1*64kB 0*128kB 0*256kB 1*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 1000kB
>> Normal: 691*4kB 17*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
>> 0*1024kB 0*2048kB 0*4096kB = 2900kB
>> 28310 total pagecache pages
>> 4385 pages in swap cache
>> Swap cache stats: add 144387, delete 140002, find 98398/115667
>> Free swap  = 889116kB
>> Total swap = 1023996kB
>> 65535 pages RAM
>> 1245 pages reserved
>> 27369 pages shared
>> 42219 pages non-shared
>> SLUB: Unable to allocate memory on node -1 (gfp=0x20)
>>   cache: kmalloc-8192, object size: 8192, buffer size: 8192, default
>> order: 3, min order: 1
>>   node 0: slabs: 133, objs: 529, free: 0
>> skbuff alloc of size 3872 failed
>>
>> 2010/9/5 Eric Dumazet <eric.dumazet@gmail.com>
>> >
>> > Le dimanche 05 septembre 2010 à 08:51 -0700, Nikhil Sethi (निखिल सेठी) a
>> > écrit :
>> > > This came back. Here is the dmesg output. It might be the problem only
>> > > happens if I have wmm_enabled=1 in my hostapd.conf. That is the only
>> > > thing that I changed yesterday, and today I saw these messages in my
>> > > logs. I will try to conform this.
>> > >
>> > >
>> > > I am running 2.6.35.4 with this patch:
>> > >
>> > >
>> > > *** 225,234 ****
>> > >    int error = 0, i;
>> > >    u32 size;
>> > >
>> > > !
>> > > ! common->rx_bufsize = roundup(IEEE80211_MAX_MPDU_LEN +
>> > > !     ah->caps.rx_status_len,
>> > > !     min(common->cachelsz, (u16)64));
>> > >
>> > >    ath9k_hw_set_rx_bufsize(ah, common->rx_bufsize -
>> > >       ah->caps.rx_status_len);
>> > > --- 225,234 ----
>> > >    int error = 0, i;
>> > >    u32 size;
>> > >
>> > > ! size = roundup(IEEE80211_MAX_MPDU_LEN + ah->caps.rx_status_len,
>> > > !                        min(common->cachelsz, (u16)64));
>> > > !         common->rx_bufsize = min_t(u32, size,
>> > > !                                    SKB_MAX_ORDER(NET_SKB_PAD +
>> > > common->cachelsz, 0));
>
>
> Its very hard to follow this thread, with a message every two months.
>
>
> As I said, this patch got a min_t() instead of max_t()
>
> http://kerneltrap.org/mailarchive/linux-kernel/2010/8/25/4611322
>
> If you still have kmalloc-8192 allocations, I suspect you dont use right
> patch.
>
>
>
>