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 I'm starting to suspect there may be a problem with some sheevaplug-specific drivers (the mv643xx ethernet driver?), because I used to run exactly the same configuration on an NSLU2 with only 32mb ram, and I never got these page allocation failures. 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. Relevant output from 'sar -A': 00:00:01 kbmemfree kbmemused %memused kbbuffers kbcached kbswpfree kbswpused %swpused kbswpcad 11:15:01 384580 131308 25.45 34644 23604 979924 0 0.00 0 11:25:01 384084 131804 25.55 35000 23628 979924 0 0.00 0 11:35:01 336496 179392 34.77 36108 64632 979924 0 0.00 0 11:45:01 341180 174708 33.87 36328 64804 979924 0 0.00 0 11:55:02 331316 184572 35.78 36964 68464 979924 0 0.00 0 12:05:01 6808 509080 98.68 3652 457636 979924 0 0.00 0 12:15:01 390752 125136 24.26 31312 15220 979924 0 0.00 0 12:25:01 385028 130860 25.37 31876 23380 979924 0 0.00 0 I'm running latest debian lenny stable with kernel: Linux version 2.6.30-2-kirkwood (Debian 2.6.30-8) (wa...@debian.org) (gcc version 4.3.4 (Debian 4.3.4-3) ) #1 Sun Sep 27 22:57:55 UTC 2009 On Sun, Aug 23, 2009 at 17:01:39 +0100, David Given wrote: > -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA1 > > When my Sheevaplug has been under load, I've been occasionally been > getting swapper page allocation failures (monster kernel log attached). > > What's particularly worrying about this is that the system's got a > gigabyte of swap, and the log claims that it's all free. So why should > it be behaving as if it's running out of memory? Given that I want to > run Java on this machine, this could be an issue! > > This problem is, in fact, strikingly similar to recurrent issue on > Debian on the NSLU2, where when the system was under heavy load the OOM > killer would erroneously start nuking processes at random, regardless of > the amount of available swap. Are there any known problems with the VM > on ARM? > > I'm using: > > Linux chur 2.6.30-rc8-kirkwood #1 Wed Jun 3 22:03:05 UTC 2009 armv5tel > GNU/Linux > > The swap is a file on a JFS partition on a RAID0 volume on USB, if that > helps. I'm about to retry with 2.6.31-rc7 and see if that helps. > > Aug 22 03:50:31 chur kernel: [25651.180000] swapper: page allocation > failure. order:1, mode:0x20 > Aug 22 03:50:31 chur kernel: [25651.180000] [<c002bcec>] > (unwind_backtrace+0x0/0xd4) from [<c008d6c8>] > (__alloc_pages_internal+0x390/0x3ac) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c008d6c8>] > (__alloc_pages_internal+0x390/0x3ac) from [<c00a9764>] > (cache_alloc_refill+0x268/0x504) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c00a9764>] > (cache_alloc_refill+0x268/0x504) from [<c00a9b64>] > (kmem_cache_alloc+0x50/0xd8) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c00a9b64>] > (kmem_cache_alloc+0x50/0xd8) from [<c01ffd58>] (sk_prot_alloc+0x24/0xc0) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c01ffd58>] > (sk_prot_alloc+0x24/0xc0) from [<c02005a0>] (sk_clone+0x14/0x1c0) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c02005a0>] > (sk_clone+0x14/0x1c0) from [<c02388d0>] (inet_csk_clone+0x14/0x9c) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c02388d0>] > (inet_csk_clone+0x14/0x9c) from [<c024ccd0>] > (tcp_create_openreq_child+0x18/0x338) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c024ccd0>] > (tcp_create_openreq_child+0x18/0x338) from [<c024ad28>] > (tcp_v4_syn_recv_sock+0x4c/0x1c0) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c024ad28>] > (tcp_v4_syn_recv_sock+0x4c/0x1c0) from [<c024caec>] > (tcp_check_req+0x250/0x41c) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c024caec>] > (tcp_check_req+0x250/0x41c) from [<c024a4ac>] (tcp_v4_do_rcv+0x1cc/0x2f4) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c024a4ac>] > (tcp_v4_do_rcv+0x1cc/0x2f4) from [<c024c768>] (tcp_v4_rcv+0x750/0x7bc) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c024c768>] > (tcp_v4_rcv+0x750/0x7bc) from [<c022f650>] > (ip_local_deliver_finish+0x1a0/0x270) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c022f650>] > (ip_local_deliver_finish+0x1a0/0x270) from [<c022f490>] > (ip_rcv_finish+0x348/0x368) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c022f490>] > (ip_rcv_finish+0x348/0x368) from [<c020b69c>] > (netif_receive_skb+0x54c/0x5a0) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c020b69c>] > (netif_receive_skb+0x54c/0x5a0) from [<bf14e1c0>] > (mv643xx_eth_poll+0x44c/0x5c8 [mv643xx_eth]) > Aug 22 03:50:31 chur kernel: [25651.180000] [<bf14e1c0>] > (mv643xx_eth_poll+0x44c/0x5c8 [mv643xx_eth]) from [<c020e214>] > (net_rx_action+0x98/0x194) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c020e214>] > (net_rx_action+0x98/0x194) from [<c0043538>] (__do_softirq+0x98/0x160) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c0043538>] > (__do_softirq+0x98/0x160) from [<c004381c>] (irq_exit+0x40/0x90) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c004381c>] > (irq_exit+0x40/0x90) from [<c0025054>] (_text+0x54/0x6c) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c0025054>] > (_text+0x54/0x6c) from [<c00259b4>] (__irq_svc+0x34/0x80) > Aug 22 03:50:31 chur kernel: [25651.180000] Exception stack(0xc0369f40 > to 0xc0369f88) > Aug 22 03:50:31 chur kernel: [25651.180000] 9f40: 000d0d2d 000003e8 > 00000000 4a8f5cf6 c036dd28 c036dd28 c0022ee8 c036bde8 > Aug 22 03:50:31 chur kernel: [25651.180000] 9f60: c036dd28 56251311 > c03edc00 00000000 32fb787f c0369f88 c0059e54 c002fb9c > Aug 22 03:50:31 chur kernel: [25651.180000] 9f80: 20000013 ffffffff > > Aug 22 03:50:31 chur kernel: [25651.180000] [<c00259b4>] > (__irq_svc+0x34/0x80) from [<c0059e54>] (do_gettimeofday+0x28/0x34) > Aug 22 03:50:31 chur kernel: [25651.180000] [<c0059e54>] > (do_gettimeofday+0x28/0x34) from [<000d0c4d>] (0xd0c4d) > Aug 22 03:50:31 chur kernel: [25651.180000] Mem-info: > Aug 22 03:50:31 chur kernel: [25651.180000] Normal per-cpu: > Aug 22 03:50:31 chur kernel: [25651.180000] CPU 0: hi: 186, btch: > 31 usd: 167 > Aug 22 03:50:31 chur kernel: [25651.180000] Active_anon:2135 > active_file:43341 inactive_anon:5588 > Aug 22 03:50:31 chur kernel: [25651.180000] inactive_file:36610 > unevictable:0 dirty:17629 writeback:0 unstable:0 > Aug 22 03:50:31 chur kernel: [25651.180000] free:904 slab:37848 > mapped:2767 pagetables:182 bounce:0 > Aug 22 03:50:31 chur kernel: [25651.180000] Normal free:3616kB > min:2884kB low:3604kB high:4324kB active_anon:8540kB > inactive_anon:22352kB active_file:173364kB inactive_file:146440kB > unevictable:0kB present:520192kB pages_scanned:0 all_unreclaimable? no > Aug 22 03:50:31 chur kernel: [25651.180000] lowmem_reserve[]: 0 0 > Aug 22 03:50:31 chur kernel: [25651.180000] Normal: 870*4kB 1*8kB 2*16kB > 1*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3616kB > Aug 22 03:50:31 chur kernel: [25651.180000] 79978 total pagecache pages > Aug 22 03:50:31 chur kernel: [25651.180000] 0 pages in swap cache > Aug 22 03:50:31 chur kernel: [25651.180000] Swap cache stats: add 0, > delete 0, find 0/0 > Aug 22 03:50:31 chur kernel: [25651.180000] Free swap = 1048568kB > Aug 22 03:50:31 chur kernel: [25651.180000] Total swap = 1048568kB > Aug 22 03:50:31 chur kernel: [25651.180000] 131072 pages of RAM > Aug 22 03:50:31 chur kernel: [25651.180000] 1285 free pages > Aug 22 03:50:31 chur kernel: [25651.180000] 2119 reserved pages > Aug 22 03:50:31 chur kernel: [25651.180000] 37848 slab pages > Aug 22 03:50:31 chur kernel: [25651.180000] 53987 pages shared > Aug 22 03:50:31 chur kernel: [25651.180000] 0 pages swap cached > > - -- > ???????????? ?????????????????????????????????????????? ??????????????? > http://www.cowlark.com ??????????????? > ??? > ??? "People who think they know everything really annoy those of us who > ??? know we don't." --- Bjarne Stroustrup > -----BEGIN PGP SIGNATURE----- > Version: GnuPG v1.4.9 (GNU/Linux) > Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ > > iD8DBQFKkWfjf9E0noFvlzgRAqGOAKCjhEFakjm7PZTID9Pt61lt9iaGzQCfVVZ7 > kYwAvi1S9tBS+o3hBg7xa+0= > =vUgL > -----END PGP SIGNATURE----- > > > -- > To UNSUBSCRIBE, email to debian-arm-requ...@lists.debian.org > with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org -- To UNSUBSCRIBE, email to debian-arm-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org
