Deciphering Linux page allocation failures

I find myself diving into Linux kernel memory management more and more these days. I thought I’d write up some helpful tips on decoding something you might see every once in a while; page allocation failures. In this particular case, we’ll look at the following example:

Dec  6 04:30:13 host kernel: echo: page allocation failure. order:9, mode:0xd0

What you see here is the following:

  • Dec 6 04:30:13 time stamp
  • host host name
  • kernel: the process that generated the message. In this case, it was the kernel itself
  • echo: the command that cause the message to be generated
  • page allocation failure. the message itself
  • order:9, the number of pages that were requested, as a power of 2
  • mode:0xd0 flags passed to the kernel memory allocator.

Regarding “order:9”, the kernel allocates pages in powers of 2. order:9 simply means it requested 2^9 pages (512), of whatever size they are. To see the size of your memory pages you can issue:

getconf PAGESIZE

In the case of this host, memory pages are 4096 bytes so the kernel was attempting to allocate 2097152 bytes (2MB). “mode:0xd0” is the flag passed to the kernel memory allocator. You can find all possible modes in include/linux/gfp.h.

“echo” caused the page allocation failure, which lead this call trace:

Dec  6 04:30:13 host kernel: Call Trace:
Dec  6 04:30:13 host kernel:  [<ffffffff8020f895>] __alloc_pages+0x2b5/0x2ce
Dec  6 04:30:13 host kernel:  [<ffffffff80212dac>] may_open+0x65/0x22f
Dec  6 04:30:13 host kernel:  [<ffffffff8023def3>] __get_free_pages+0x30/0x69
Dec  6 04:30:13 host kernel:  [<ffffffff884a9aa0>] :ip_conntrack:alloc_hashtable+0x33/0x7a
Dec  6 04:30:13 host kernel:  [<ffffffff884a9b56>] :ip_conntrack:set_hashsize+0x49/0x12a
Dec  6 04:30:13 host kernel:  [<ffffffff8029a32b>] param_attr_store+0x1a/0x29
Dec  6 04:30:13 host kernel:  [<ffffffff8029a37f>] module_attr_store+0x21/0x25
Dec  6 04:30:13 host kernel:  [<ffffffff802fdc83>] sysfs_write_file+0xb9/0xe8
Dec  6 04:30:13 host kernel:  [<ffffffff802171a7>] vfs_write+0xce/0x174
Dec  6 04:30:13 host kernel:  [<ffffffff802179df>] sys_write+0x45/0x6e
Dec  6 04:30:13 host kernel:  [<ffffffff80260106>] system_call+0x86/0x8b
Dec  6 04:30:13 host kernel:  [<ffffffff80260080>] system_call+0x0/0x8b

The first line is where the kernel failed, in alloc_pages, which is no surprise. As we go a bit deeper in the stack trace you can see that the calling function was :ip_conntrack:alloc_hashtable, so we died during an attempt to allocate 2MB to the ip_conntrack hash table.

After the above, the kernel dumps a fair amount of information (Mem-info) about the memory state of the host. If you’re interested in the kernel code involved, see show_mem() in lib/show_mem.c, and show_free_areas() in mm/page_alloc.c.

Dec  6 04:30:13 host kernel: Mem-info:
Dec  6 04:30:13 host kernel: DMA per-cpu:
Dec  6 04:30:13 host kernel: cpu 0 hot: high 186, batch 31 used:32
Dec  6 04:30:13 host kernel: cpu 0 cold: high 62, batch 15 used:57
Dec  6 04:30:13 host kernel: cpu 1 hot: high 186, batch 31 used:96
Dec  6 04:30:13 host kernel: cpu 1 cold: high 62, batch 15 used:11
Dec  6 04:30:13 host kernel: cpu 2 hot: high 186, batch 31 used:90
Dec  6 04:30:13 host kernel: cpu 2 cold: high 62, batch 15 used:53
Dec  6 04:30:13 host kernel: cpu 3 hot: high 186, batch 31 used:102
Dec  6 04:30:13 host kernel: cpu 3 cold: high 62, batch 15 used:7
Dec  6 04:30:13 host kernel: cpu 4 hot: high 186, batch 31 used:136
Dec  6 04:30:13 host kernel: cpu 4 cold: high 62, batch 15 used:14
Dec  6 04:30:13 host kernel: cpu 5 hot: high 186, batch 31 used:39
Dec  6 04:30:13 host kernel: cpu 5 cold: high 62, batch 15 used:3
Dec  6 04:30:13 host kernel: cpu 6 hot: high 186, batch 31 used:163
Dec  6 04:30:13 host kernel: cpu 6 cold: high 62, batch 15 used:12
Dec  6 04:30:13 host kernel: cpu 7 hot: high 186, batch 31 used:74
Dec  6 04:30:13 host kernel: cpu 7 cold: high 62, batch 15 used:0
Dec  6 04:30:13 host kernel: DMA32 per-cpu: empty
Dec  6 04:30:13 host kernel: Normal per-cpu: empty
Dec  6 04:30:13 host kernel: HighMem per-cpu: empty
Dec  6 04:30:13 host kernel: Free pages:       19348kB (0kB HighMem)
Dec  6 04:30:13 host kernel: Active:67877 inactive:18034 dirty:110 writeback:0 unstable:0 free:5017 slab:11928 mapped-file:3125 mapped-anon:28202 pagetables:854
Dec  6 04:30:13 host kernel: DMA free:21268kB min:2916kB low:3644kB high:4372kB active:271488kB inactive:70236kB present:532480kB pages_scanned:35 all_unreclaimable? no
Dec  6 04:30:13 host kernel: lowmem_reserve[]: 0 0 0 0
Dec  6 04:30:13 host kernel: DMA32 free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Dec  6 04:30:13 host kernel: lowmem_reserve[]: 0 0 0 0
Dec  6 04:30:13 host kernel: Normal free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Dec  6 04:30:13 host kernel: lowmem_reserve[]: 0 0 0 0
Dec  6 04:30:13 host kernel: HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Dec  6 04:30:13 host kernel: lowmem_reserve[]: 0 0 0 0
Dec  6 04:30:13 host kernel: DMA: 2090*4kB 1339*8kB 99*16kB 17*32kB 5*64kB 5*128kB 0*256kB 2*512kB 1*1024kB 0*2048kB 0*4096kB = 24208kB
Dec  6 04:30:13 host kernel: DMA32: empty
Dec  6 04:30:13 host kernel: Normal: empty
Dec  6 04:30:13 host kernel: HighMem: empty
Dec  6 04:30:13 host kernel: 61160 pagecache pages
Dec  6 04:30:13 host kernel: Swap cache: add 428356, delete 421485, find 49760550/49818299, race 0+197
Dec  6 04:30:13 host kernel: Free swap  = 1986220kB
Dec  6 04:30:13 host kernel: Total swap = 2096472kB
Dec  6 04:30:13 host kernel: Free swap:       1986220kB
Dec  6 04:30:13 host kernel: 133120 pages of RAM
Dec  6 04:30:13 host kernel: 22508 reserved pages
Dec  6 04:30:13 host kernel: 42739 pages shared
Dec  6 04:30:13 host kernel: 6835 pages swap cached

Finally we see a message about falling back to vmalloc.

Dec  6 04:30:13 host kernel: ip_conntrack: falling back to vmalloc.

Since the kernel attempts to kmalloc() a contiguous block of memory, and fails, it falls back to vmalloc() which can allocate non-contiguous blocks of memory.