Nope! Still doing it...

swapper: page allocation failure: order:4, mode:0x20
Pid: 0, comm: swapper Not tainted 3.0.4-linode38 #1
Call Trace:
 [<c018b258>] ? warn_alloc_failed+0x98/0x100
 [<c018baa4>] ? __alloc_pages_nodemask+0x3f4/0x630
 [<c014000a>] ? mod_timer_pending+0xba/0x110
 [<c01b22b3>] ? T.833+0xb3/0x2e0
 [<c01b2726>] ? cache_alloc_refill+0x246/0x290
 [<c060f0ff>] ? ipt_do_table+0x24f/0x580
 [<c01b282d>] ? __kmalloc+0xbd/0xd0
 [<c053a7fe>] ? pskb_expand_head+0x12e/0x200
 [<c053ad3d>] ? __pskb_pull_tail+0x4d/0x2b0
 [<c0607ad3>] ? ipv4_confirm+0xf3/0x1b0
etc etc etc

The dump appears to be the same as previous message.

_________________
Rgds
Stephen
(Linux user since kernel version 0.11)

I'm having the same problem. However just on one of Linodes. What i noticed is - this happens on Linode that have big load in sense of CPU usage (around 200-250%).

My temporar solution is to use older kernel and time to time to restart apache/nginx/memcached. Because over time kernel moves some data to swap even when there is plenty of ram and at one point it starts to OOM without aparent reason. However that is not bulletproof solution - after about a week or so server stops any traffic and in lish i can see a lot of UFW messages.

I hope that next kernel will fix whatever is causing this.

I took a look at my logs this morning, and indeed, I'm seeing it on my busy nodes. On both, vm.min_free_kbytes = 2906. I'm upping to 4096 and rebooting three times to see if that helps.

==> /var/log/remote-2600:3c03::f03c:91ff:fe96:ce69.log <==
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: lighttpd: page allocation failure: order:3, mode:0x20
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Pid: 2098, comm: lighttpd Not tainted 3.0.4-linode38 #1
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Call Trace:
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c018b258>] ? warn_alloc_failed+0x98/0x100
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c018baa4>] ? __alloc_pages_nodemask+0x3f4/0x630
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c014000a>] ? mod_timer_pending+0xba/0x110
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b22b3>] ? T.833+0xb3/0x2e0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b2726>] ? cache_alloc_refill+0x246/0x290
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c060f0ff>] ? ipt_do_table+0x24f/0x580
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b282d>] ? __kmalloc+0xbd/0xd0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c053a7fe>] ? pskb_expand_head+0x12e/0x200
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c053ad3d>] ? __pskb_pull_tail+0x4d/0x2b0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0607ad3>] ? ipv4_confirm+0xf3/0x1b0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05436dd>] ? dev_hard_start_xmit+0x1dd/0x3e0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c8020>] ? ip_finish_output2+0x260/0x260
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c8020>] ? ip_finish_output2+0x260/0x260
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0557a62>] ? sch_direct_xmit+0xb2/0x170
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05439d9>] ? dev_queue_xmit+0xf9/0x320
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c815b>] ? ip_finish_output+0x13b/0x300
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c83ca>] ? ip_output+0xaa/0xe0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c7568>] ? ip_local_out+0x18/0x20
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05daf25>] ? tcp_transmit_skb+0x385/0x670
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05dd965>] ? tcp_write_xmit+0x1e5/0x4f0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05ddcd4>] ? __tcp_push_pending_frames+0x24/0x90
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05d0aae>] ? tcp_sendmsg+0x81e/0xb30
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0105c27>] ? xen_force_evtchn_callback+0x17/0x30
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0106404>] ? check_events+0x8/0xc
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05eed37>] ? inet_sendmsg+0x47/0xb0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0532366>] ? sock_aio_write+0x116/0x170
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05d8520>] ? tcp_clean_rtx_queue+0x590/0x8b0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0614a8e>] ? bictcp_cong_avoid+0x1e/0x420
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0532250>] ? sock_aio_dtor+0x10/0x10
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b5036>] ? do_sync_readv_writev+0xb6/0xf0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0105c27>] ? xen_force_evtchn_callback+0x17/0x30
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b52b6>] ? rw_verify_area+0x66/0x120
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b57ba>] ? do_readv_writev+0xaa/0x1a0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0532250>] ? sock_aio_dtor+0x10/0x10
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0535233>] ? sock_common_setsockopt+0x23/0x30
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05338ec>] ? sys_setsockopt+0x6c/0xd0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b58ee>] ? vfs_writev+0x3e/0x60
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b5a11>] ? sys_writev+0x41/0xa0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c06bfb91>] ? syscall_call+0x7/0xb
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c06b0000>] ? sctp_err_lookup+0x90/0x110
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Mem-Info:
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA per-cpu:
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    0: hi:    0, btch:   1 usd:   0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    1: hi:    0, btch:   1 usd:   0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    2: hi:    0, btch:   1 usd:   0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    3: hi:    0, btch:   1 usd:   0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal per-cpu:
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    0: hi:  186, btch:  31 usd: 152
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    1: hi:  186, btch:  31 usd: 157
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    2: hi:  186, btch:  31 usd: 178
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    3: hi:  186, btch:  31 usd:  50
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: active_anon:36638 inactive_anon:36659 isolated_anon:32
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: active_file:21023 inactive_file:24423 isolated_file:0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: unevictable:0 dirty:12 writeback:364 unstable:0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: free:1439 slab_reclaimable:1247 slab_unreclaimable:2337
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: mapped:4976 shmem:26429 pagetables:368 bounce:0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA free:2168kB min:84kB low:104kB high:124kB active_anon:2104kB inactive_anon:2220kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:1120kB mapped:12kB shmem:16kB slab_reclaimable:412kB slab_unreclaimable:200kB kernel_stack:16kB pagetables:80kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: lowmem_reserve[]: 0 500 500 500
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal free:3588kB min:2816kB low:3520kB high:4224kB active_anon:144448kB inactive_anon:144416kB active_file:84092kB inactive_file:97692kB unevictable:0kB isolated(anon):128kB isolated(file):0kB present:512064kB mlocked:0kB dirty:48kB writeback:336kB mapped:19892kB shmem:105700kB slab_reclaimable:4576kB slab_unreclaimable:9148kB kernel_stack:568kB pagetables:1392kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: lowmem_reserve[]: 0 0 0 0
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA: 23*4kB 132*8kB 63*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2156kB
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal: 421*4kB 228*8kB 5*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3588kB
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 91700 total pagecache pages
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 19833 pages in swap cache
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Swap cache stats: add 10930739, delete 10910906, find 34210627/35708199
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Free swap  = 116176kB
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: Total swap = 262140kB
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 133104 pages RAM
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 0 pages HighMem
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 5833 pages reserved
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 18151 pages shared
Sep 30 11:53:20 2600:3c03::f03c:91ff:fe96:ce69 kernel: 110656 pages non-shared

==> /var/log/remote-2600:3c03::f03c:91ff:fe96:1dc9.log <==
Sep 30 13:30:15 2600:3c03::f03c:91ff:fe96:1dc9 kernel: nginx: page allocation failure: order:1, mode:0x20
Sep 30 13:30:15 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Pid: 18595, comm: nginx Not tainted 3.0.4-linode38 #1
Sep 30 13:30:15 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Call Trace:
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c018b258>] ? warn_alloc_failed+0x98/0x100
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c018baa4>] ? __alloc_pages_nodemask+0x3f4/0x630
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01b22b3>] ? T.833+0xb3/0x2e0
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01b2726>] ? cache_alloc_refill+0x246/0x290
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0105c27>] ? xen_force_evtchn_callback+0x17/0x30
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01b20e9>] ? kmem_cache_alloc+0x79/0x90
Sep 30 13:30:16 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0536adf>] ? sk_prot_alloc+0x2f/0x100
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0536c75>] ? sk_clone+0x15/0x260
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05cc14b>] ? inet_csk_clone+0xb/0xb0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e28a7>] ? tcp_create_openreq_child+0x17/0x400
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c060f0ff>] ? ipt_do_table+0x24f/0x580
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e10b1>] ? tcp_v4_syn_recv_sock+0x31/0x1c0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e2610>] ? tcp_check_req+0x200/0x480
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0607ad3>] ? ipv4_confirm+0xf3/0x1b0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e0694>] ? tcp_v4_hnd_req+0x54/0x100
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c057fb3c>] ? nf_iterate+0x6c/0x90
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e0861>] ? tcp_v4_do_rcv+0x121/0x1a0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0552977>] ? sk_filter+0x17/0x80
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05e0f99>] ? tcp_v4_rcv+0x6b9/0x7a0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05c2fc7>] ? ip_local_deliver_finish+0x97/0x220
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05c2f30>] ? ip_rcv+0x320/0x320
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05c298b>] ? ip_rcv_finish+0xfb/0x380
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05c2890>] ? inet_del_protocol+0x30/0x30
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0540dae>] ? __netif_receive_skb+0x2fe/0x370
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0540eea>] ? process_backlog+0xca/0x1a0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0542d2a>] ? net_rx_action+0xea/0x190
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0139cfc>] ? __do_softirq+0x7c/0x110
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0139c80>] ? irq_enter+0x60/0x60
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: <IRQ>  [<c0139b91>] ? local_bh_enable_ip+0x71/0x80
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c05ef195>] ? inet_stream_connect+0x55/0x1b0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0533c05>] ? sys_connect+0xd5/0xf0
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0105c27>] ? xen_force_evtchn_callback+0x17/0x30
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0106404>] ? check_events+0x8/0xc
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01063fb>] ? xen_restore_fl_direct_reloc+0x4/0x4
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c06bf8b1>] ? _raw_spin_unlock_irqrestore+0x11/0x20
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0105c27>] ? xen_force_evtchn_callback+0x17/0x30
Sep 30 13:30:26 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0106404>] ? check_events+0x8/0xc
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01063fb>] ? xen_restore_fl_direct_reloc+0x4/0x4
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c06bf8b1>] ? _raw_spin_unlock_irqrestore+0x11/0x20
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c01e989d>] ? ep_insert+0x14d/0x220
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c0534c2e>] ? sys_socketcall+0x28e/0x2e0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c06bfb91>] ? syscall_call+0x7/0xb
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: [<c06b0000>] ? sctp_err_lookup+0x90/0x110
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Mem-Info:
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: DMA per-cpu:
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    0: hi:    0, btch:   1 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    1: hi:    0, btch:   1 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    2: hi:    0, btch:   1 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    3: hi:    0, btch:   1 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Normal per-cpu:
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    0: hi:  186, btch:  31 usd:  28
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    1: hi:  186, btch:  31 usd:  30
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    2: hi:  186, btch:  31 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: CPU    3: hi:  186, btch:  31 usd:   0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: active_anon:10230 inactive_anon:10362 isolated_anon:32
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: active_file:35748 inactive_file:54897 isolated_file:0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: unevictable:0 dirty:157 writeback:649 unstable:0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: free:1246 slab_reclaimable:4855 slab_unreclaimable:6029
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: mapped:7045 shmem:1884 pagetables:736 bounce:0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: DMA free:2092kB min:84kB low:104kB high:124kB active_anon:944kB inactive_anon:1016kB active_file:0kB inactive_file:196kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:888kB mapped:0kB shmem:0kB slab_reclaimable:2308kB slab_unreclaimable:448kB kernel_stack:112kB pagetables:160kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: lowmem_reserve[]: 0 500 500 500
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Normal free:2892kB min:2816kB low:3520kB high:4224kB active_anon:39976kB inactive_anon:40432kB active_file:142992kB inactive_file:219392kB unevictable:0kB isolated(anon):128kB isolated(file):0kB present:512064kB mlocked:0kB dirty:628kB writeback:1708kB mapped:28180kB shmem:7536kB slab_reclaimable:17112kB slab_unreclaimable:23668kB kernel_stack:1328kB pagetables:2784kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: lowmem_reserve[]: 0 0 0 0
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: DMA: 523*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2092kB
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Normal: 589*4kB 57*8kB 5*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2892kB
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 95982 total pagecache pages
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 3433 pages in swap cache
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Swap cache stats: add 5523129, delete 5519696, find 39134429/39792794
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Free swap  = 95340kB
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: Total swap = 262140kB
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 133104 pages RAM
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 0 pages HighMem
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 5833 pages reserved
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 60210 pages shared
Sep 30 13:30:27 2600:3c03::f03c:91ff:fe96:1dc9 kernel: 93821 pages non-shared

_________________

/* TODO: need to add signature to posts */

I'm still getting them with -linode38 and vm.min_free_kbytes = 4096:

==> /var/log/remote-2600:3c03::f03c:91ff:fe96:ce69.log <==
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: swapper: page allocation failure: order:3, mode:0x20
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Pid: 0, comm: swapper Not tainted 3.0.4-linode38 #1
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Call Trace:
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c018b258>] ? warn_alloc_failed+0x98/0x100
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c018baa4>] ? __alloc_pages_nodemask+0x3f4/0x630
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b22b3>] ? T.833+0xb3/0x2e0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b2726>] ? cache_alloc_refill+0x246/0x290
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c060f0ff>] ? ipt_do_table+0x24f/0x580
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01b282d>] ? __kmalloc+0xbd/0xd0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c053a7fe>] ? pskb_expand_head+0x12e/0x200
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c053ad3d>] ? __pskb_pull_tail+0x4d/0x2b0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0607ad3>] ? ipv4_confirm+0xf3/0x1b0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05436dd>] ? dev_hard_start_xmit+0x1dd/0x3e0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c8020>] ? ip_finish_output2+0x260/0x260
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c8020>] ? ip_finish_output2+0x260/0x260
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0557a62>] ? sch_direct_xmit+0xb2/0x170
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05439d9>] ? dev_queue_xmit+0xf9/0x320
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c815b>] ? ip_finish_output+0x13b/0x300
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c83ca>] ? ip_output+0xaa/0xe0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c7568>] ? ip_local_out+0x18/0x20
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05daf25>] ? tcp_transmit_skb+0x385/0x670
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05dd965>] ? tcp_write_xmit+0x1e5/0x4f0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05ddcd4>] ? __tcp_push_pending_frames+0x24/0x90
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05d9cf2>] ? tcp_rcv_established+0x3d2/0x610
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05e080e>] ? tcp_v4_do_rcv+0xce/0x1a0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05e0f99>] ? tcp_v4_rcv+0x6b9/0x7a0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c2fc7>] ? ip_local_deliver_finish+0x97/0x220
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c2f30>] ? ip_rcv+0x320/0x320
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c05c298b>] ? ip_rcv_finish+0xfb/0x380
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0540dae>] ? __netif_receive_skb+0x2fe/0x370
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0542597>] ? netif_receive_skb+0x67/0x70
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c04e35fc>] ? handle_incoming_queue+0x17c/0x250
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c04e38ec>] ? xennet_poll+0x21c/0x540
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0542d2a>] ? net_rx_action+0xea/0x190
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0139cfc>] ? __do_softirq+0x7c/0x110
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0139c80>] ? irq_enter+0x60/0x60
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: <IRQ>  [<c0139ade>] ? irq_exit+0x6e/0xa0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c047829d>] ? xen_evtchn_do_upcall+0x1d/0x30
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c06c0947>] ? xen_do_upcall+0x7/0xc
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c01013a7>] ? hypercall_page+0x3a7/0x1000
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0105c7f>] ? xen_safe_halt+0xf/0x20
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c010f41e>] ? default_idle+0x2e/0x60
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c0107f72>] ? cpu_idle+0x42/0x70
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c086977f>] ? start_kernel+0x2ce/0x2d3
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c08692ef>] ? kernel_init+0x112/0x112
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: [<c086c943>] ? xen_start_kernel+0x4f7/0x4ff
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Mem-Info:
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA per-cpu:
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    0: hi:    0, btch:   1 usd:   0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    1: hi:    0, btch:   1 usd:   0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    2: hi:    0, btch:   1 usd:   0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    3: hi:    0, btch:   1 usd:   0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal per-cpu:
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    0: hi:  186, btch:  31 usd: 139
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    1: hi:  186, btch:  31 usd:  27
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    2: hi:  186, btch:  31 usd:  23
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: CPU    3: hi:  186, btch:  31 usd: 167
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: active_anon:35584 inactive_anon:35624 isolated_anon:0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: active_file:19975 inactive_file:20016 isolated_file:0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: unevictable:0 dirty:16 writeback:868 unstable:0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: free:9374 slab_reclaimable:1040 slab_unreclaimable:2331
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: mapped:6137 shmem:29185 pagetables:415 bounce:0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA free:2532kB min:120kB low:148kB high:180kB active_anon:1724kB inactive_anon:1916kB active_file:76kB inactive_file:184kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:0kB mapped:16kB shmem:16kB slab_reclaimable:136kB slab_unreclaimable:520kB kernel_stack:0kB pagetables:132kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: lowmem_reserve[]: 0 500 500 500
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal free:34964kB min:3972kB low:4964kB high:5956kB active_anon:140612kB inactive_anon:140580kB active_file:79824kB inactive_file:79880kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:512064kB mlocked:0kB dirty:64kB writeback:3472kB mapped:24532kB shmem:116724kB slab_reclaimable:4024kB slab_unreclaimable:8804kB kernel_stack:600kB pagetables:1528kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: lowmem_reserve[]: 0 0 0 0
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: DMA: 221*4kB 182*8kB 12*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2532kB
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Normal: 5751*4kB 1367*8kB 64*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 34964kB
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 80575 total pagecache pages
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 11428 pages in swap cache
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Swap cache stats: add 3503073, delete 3491645, find 8773626/9187228
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Free swap  = 151020kB
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: Total swap = 262140kB
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 133104 pages RAM
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 0 pages HighMem
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 5833 pages reserved
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 21491 pages shared
Oct  1 16:21:03 2600:3c03::f03c:91ff:fe96:ce69 kernel: 102684 pages non-shared

For data nerds, some annotated grepping and counting:

$ zgrep -h "page allocation failure" remote-2600:3c03:*:1dc9.log* | cut -b1-6 | sort | uniq -c
Sep 4: 2.6.39.1-linode34 #1
     11 Sep  4
     16 Sep  5
      3 Sep  6
      3 Sep  7
     16 Sep  8
     12 Sep  9
     11 Sep 10
      8 Sep 11
      4 Sep 12
      7 Sep 13
      5 Sep 14
     21 Sep 15
     18 Sep 16
     14 Sep 17
     10 Sep 18
     21 Sep 19
     12 Sep 20
     14 Sep 21
     13 Sep 22
    634 Sep 23
      6 Sep 24
Sep 25: 3.0.4-linode38 #1
      5 Sep 25
     24 Sep 26
     18 Sep 27
     41 Sep 28
      8 Sep 29
     52 Sep 30
    211 Oct  1

$ zgrep -h "page allocation failure" remote-2600:3c03:*:ce69.log* | cut -b1-6 | sort | uniq -c
Aug 19: 2.6.39.1-linode34 #1
     22 Aug 19
     34 Aug 20
     41 Aug 21
     36 Aug 22
     43 Aug 23
     37 Aug 24
     36 Aug 25
     50 Aug 26
     43 Aug 27
     75 Aug 28
     57 Aug 29
     58 Aug 30
     81 Aug 31
     55 Sep  1
     80 Sep  2
     62 Sep  3
(gap due to the remote logging system being broken)
Sep 17: 3.0.4-linode36 #1
     10 Sep 17
     88 Sep 18
     54 Sep 19
     53 Sep 20
     32 Sep 21
     66 Sep 22
    148 Sep 23
     48 Sep 24
    163 Sep 25
Sep 26: 3.0.4-linode38 #1
     92 Sep 26
    223 Sep 27
    224 Sep 28
    238 Sep 29
    170 Sep 30
    145 Oct  1

On the first system (1dc9), note the spike on September 23... that happens to correspond to a full backup rsync, but there was also one on September 6. For the second system (ce69), there was also a full backup rsync on September 23. (I was testing the backup server that day.)

_________________

/* TODO: need to add signature to posts */

p.s. if anyone wants my kernel logs for some sort of analysis, let me know.

rtucker@hennepin:/var/log$ zgrep -h "kernel:" remote-2600:3c03:*:ce69.log* remote-2600:3c03:*:1dc9.log* | wc
 297278 2893029 31386088

_________________

/* TODO: need to add signature to posts */

Hmm, funky... a couple of days ago I made some DNS changes. One of the primary impacts of the DNS is that I now talk IP6 between my home and my linode; previously I spoke IP4.

And I haven't seen any page allocation errors in the past 2 days, either.

Coincidence?

_________________
Rgds

Stephen

(Linux user since kernel version 0.11)

You know, interesting you mentioned that...

A scrollback through my recent few half-dozen PAFs shows many mentions of IPv4-related things in the call trace. Also, in my histogrammetric(*) analysis, I mentioned I was testing the backup server... you wanna know what I was testing? Moving the rsyncs from IPv4 to IPv6. Post-IPv6, no more spikes...

Both of these servers have a fair bit of IPv4 traffic (~130 packets/second for one, and probably within an order of magnitude for the other, although it is not yet graphed). Obviously, not as much IPv6 traffic yet.

If it is IPv4-related, then great news! It will fix itself within the next century!

(*) i just made that word up

_________________

/* TODO: need to add signature to posts */

I'm getting the same sort of messages. After reading this thread, I can guess what I did to trigger it. Posting here in case it helps someone somewhere.

I recently enabled IPv6 on a linode, and used the reboot to switch to a version 3 kernel at the same time. Everything was running fine, except one remote system could not connect anymore to exchange data. Problem was obvious: the system was now trying to connect via IPv6, but that particular service was not set up to accept IPv6 connections.

I took the easy way out, and told the remote system to always use IPv4 to connect. The system could now connect, but I started getting log messages similar to those others have posted.

Thought at first it might be related to vm.min_free_kbytes being too low (had similar problem on another linode months ago, with an older kernel). So I upped that. But the log messages persisted.

Then I found this thread. Will now change the service to accept IPv6 connections, and see what happens.

Of course, it's pretty worrying if there's a problem with IPv4 connections. I'll hold off updating the kernel on my web-serving linodes. They already do IPv6, but use older kernels.

I also have a server which keeps OOM for no apparent reason. Just stumbled across this thread and I have the same messages in my kernel log.

I'm running latest 3.0 kernel (3.0.4-linode38) with Debian Squeeze 32bit on a 512mb Linode.

Have increased min_free_kbytes to 4096 as suggested and will see if that fixes the problem...

As far as I can tell, the error messages are independent of RAM usage and are benign, so odds are good your OOM problem is elsewhere.

I see. Well, I've posted in this thread as it seems I'm experiencing the same bizarre problem with the same setup. I'd be very grateful for some advice on how to troubleshoot. I appear to have buckets of free memory but it's still going into swap!

Has anyone made progress on the page-allocation-failure-despite-plenty-of-free-memory issue? I too am on 3.0.4-linode38 and have vm.min_free_kbytes = 8192 and still getting it, though I just found this thread a couple hours ago and the normal periods where it's most likely to show up (during an rsync) haven't fired yet.

And indeed, it is seemingly based on IPv4 traffic somehow. Usually swapper/kswapd0 is the process implicated, but I've also seen sshd, rsync, munin-graph (?), iostat (!?)... all with ipv4_confirm et al in the stack trace.

Just grow your min_free_kbytes setting until you get to place where the warnings stop.
And, if you have a high level of iowaits, check if you can reduce the disk contention - then you may "sneak past" with lower value of min_free_kbytes.

_________________
rsk, providing useless advice on the Internet since 2005.

I've been bumping it with the hopes that the problem eventually goes away, but given my amount of free memory and no anomalies in the Munin graphs on these boxes, I would think vm.min_free_kbytes is a red herring. But either way, it seems like a regression, and if Linode folks need guinea pigs, I'm saying I'm game to test some kernels or whatever. :)

I am bumping it as well. Same for me. NJ Linode uname -r returns 3.0.18-linode43
No IPV6... maybe it's not disabled completely? maybe I need to go to a different kernel... I dun know for sure but help