Re: page allocation failures in mv643xx_eth_poll (was Re: Swapper problems?)
On Sun, Nov 22, 2009 at 12:46:07PM +0100, Frode E. Moe wrote:
> Did anyone figure this one out? I'm getting these regularly on
> my Sheevaplug. I have a cron job that runs every 4 hours running
> tar to create a ~1.5gb backup file. Sometimes (every few days)
> it causes the following dmesg output:
>
> Nov 22 12:01:36 chaos kernel: [1360924.210000] tar: page allocation failure. order:1, mode:0x20
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c002cd68>] (unwind_backtrace+0x0/0xdc) from [<c00906b0>] (__alloc_pages_internal+0x3c0/0x3e4)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c00906b0>] (__alloc_pages_internal+0x3c0/0x3e4) from [<c00acdc4>] (cache_alloc_refill+0x268/0x528)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c00acdc4>] (cache_alloc_refill+0x268/0x528) from [<c00ad1ec>] (kmem_cache_alloc+0x50/0xdc)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c00ad1ec>] (kmem_cache_alloc+0x50/0xdc) from [<c0205ce0>] (sk_prot_alloc+0x28/0xe8)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0205ce0>] (sk_prot_alloc+0x28/0xe8) from [<c0206190>] (sk_clone+0x14/0x1d0)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0206190>] (sk_clone+0x14/0x1d0) from [<c023e2c4>] (inet_csk_clone+0x14/0x98)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c023e2c4>] (inet_csk_clone+0x14/0x98) from [<c0253704>] (tcp_create_openreq_child+0x18/0x340)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0253704>] (tcp_create_openreq_child+0x18/0x340) from [<c0252854>] (tcp_v4_syn_recv_sock+0x4c/0x208)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0252854>] (tcp_v4_syn_recv_sock+0x4c/0x208) from [<c0253528>] (tcp_check_req+0x254/0x418)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0253528>] (tcp_check_req+0x254/0x418) from [<c0251ab8>] (tcp_v4_do_rcv+0x218/0x348)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0251ab8>] (tcp_v4_do_rcv+0x218/0x348) from [<c02520dc>] (tcp_v4_rcv+0x4f4/0x7e0)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c02520dc>] (tcp_v4_rcv+0x4f4/0x7e0) from [<c02356c0>] (ip_local_deliver_finish+0x190/0x274)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c02356c0>] (ip_local_deliver_finish+0x190/0x274) from [<c0235258>] (ip_rcv_finish+0x320/0x340)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0235258>] (ip_rcv_finish+0x320/0x340) from [<c02115cc>] (netif_receive_skb+0x538/0x584)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c02115cc>] (netif_receive_skb+0x538/0x584) from [<bf07a868>] (mv643xx_eth_poll+0x4d0/0x670 [mv643xx_eth])
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<bf07a868>] (mv643xx_eth_poll+0x4d0/0x670 [mv643xx_eth]) from [<c0211cec>] (net_rx_action+0x90/0x1c0)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0211cec>] (net_rx_action+0x90/0x1c0) from [<c0044d50>] (__do_softirq+0xa4/0x180)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0044d50>] (__do_softirq+0xa4/0x180) from [<c0044e6c>] (irq_exit+0x40/0x90)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0044e6c>] (irq_exit+0x40/0x90) from [<c0026054>] (_text+0x54/0x6c)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0026054>] (_text+0x54/0x6c) from [<c0026a14>] (__irq_svc+0x34/0x80)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Exception stack(0xda991a28 to 0xda991a70)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 1a20: c5d01248 d6441948 d6441948 00000000 c3cda3c8 ded8d200
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 1a40: bf041bb6 c3cda3c8 00002694 d66a7748 c0e80440 d6441948 c788f240 da991a70
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 1a60: bf03ed94 bf01d374 60000013 ffffffff
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<c0026a14>] (__irq_svc+0x34/0x80) from [<bf03ed94>] (__ext3_journal_dirty_metadata+0x20/0x50 [ext3])
> Nov 22 12:01:36 chaos kernel: [1360924.210000] [<bf03ed94>] (__ext3_journal_dirty_metadata+0x20/0x50 [ext3]) from [<00002694>] (0x2694)
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Mem-info:
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Normal per-cpu:
> Nov 22 12:01:36 chaos kernel: [1360924.210000] CPU 0: hi: 186, btch: 31 usd: 78
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Active_anon:949 active_file:4664 inactive_anon:6816
> Nov 22 12:01:36 chaos kernel: [1360924.210000] inactive_file:109966 unevictable:0 dirty:20769 writeback:1295 unstable:0
> Nov 22 12:01:36 chaos kernel: [1360924.210000] free:1141 slab:3916 mapped:777 pagetables:251 bounce:0
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Normal free:4564kB min:2884kB low:3604kB high:4324kB active_anon:3796kB inactive_anon:27264kB active_file:18656kB inactive_file:439864kB unevictable:0kB present:520192kB pages_scanned:0 all_unreclaimable? no
> Nov 22 12:01:36 chaos kernel: [1360924.210000] lowmem_reserve[]: 0 0
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Normal: 1095*4kB 5*8kB 3*16kB 1*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4564kB
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 114774 total pagecache pages
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 0 pages in swap cache
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Swap cache stats: add 0, delete 0, find 0/0
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Free swap = 979924kB
> Nov 22 12:01:36 chaos kernel: [1360924.210000] Total swap = 979924kB
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 131072 pages of RAM
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 1422 free pages
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 2111 reserved pages
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 3916 slab pages
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 64911 pages shared
> Nov 22 12:01:36 chaos kernel: [1360924.210000] 0 pages swap cached
This just means that there was a temporary memory shortage, as a
result of which an incoming packet couldn't be processed at this time.
> I'm starting to suspect there may be a problem with some
> sheevaplug-specific drivers (the mv643xx ethernet driver?),
None that I know of. This can trigger on any network driver,
actually, if you stress it hard enough.
> because I used to run exactly the same configuration on an NSLU2
> with only 32mb ram, and I never got these page allocation failures.
Earlier kernels didn't report in-kernel memory allocation failures,
as far as I remember.
> The stacktrace ALWAYS contains
> tcp_v4_syn_recv_sock .... mv643xx_eth_poll ...
>
> Strangely it looks like the tar process completes successfully, or at least
> I can't remember seeing anything odd in the cron mail output.
It was just a temporary memory shortage, and not a fatal error.
Whatever job you were running will eventually just complete as if
nothing happened.
Reply to: