Hi All,
I'm stressing a system with apachebench. As one scales up work on a system obviously there's always a point where the wheels fall off, the engine explodes or something else exciting happens. But as Han Solo would say ... "hold together baby....", I'd like to eek out as much as I can. (If you're really interested, here's what I'm up to : http://fullshovel.wordpress.com/ start with part 1)
In this case with apachebench, I'm geting the following allocation errors in the kernel and need a little help deciphering. It sure looks like there's plenty of space to swap out however if I have this right, we're getting so much network traffic that the kernel gets inundated and it OOMs in the network stack.
I did later try setting sysctl -w vm.min_free_kbytes=32768 but that didn't really seem to help.
The much more complete dmesg dump is located at http://people.linaro.org/~tgall/dmesg-dump.txt
Thanks in advance for thoughts and advise.
[127089.668487] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.675994] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.683502] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.690979] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.698455] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.705932] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.713409] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.720886] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127089.728363] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127096.934051] Initial hdmi_get_current_hpd says disconnected [127100.245117] warn_alloc_failed: 52 callbacks suppressed [127100.245117] swapper/0: page allocation failure: order:3, mode:0x20 [127100.245117] [<8001b8d0>] (unwind_backtrace+0x0/0xec) from [<806905d0>] (dump_stack+0x20/0x24) [127100.245544] [<806905d0>] (dump_stack+0x20/0x24) from [<800fe390>] (warn_alloc_failed+0xfc/0x11c) [127100.245544] [<800fe390>] (warn_alloc_failed+0xfc/0x11c) from [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) [127100.245666] [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) from [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) [127100.245666] [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) from [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) [127100.245666] [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) from [<8069570c>] (cache_alloc_refill+0x21c/0x274) [127100.245819] [<8069570c>] (cache_alloc_refill+0x21c/0x274) from [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) [127100.245910] [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) from [<8057a37c>] (__alloc_skb+0x60/0xfc) [127100.245971] [<8057a37c>] (__alloc_skb+0x60/0xfc) from [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) [127100.245971] [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) from [<8049dbb8>] (rx_submit+0x2c/0x1d4) [127100.245971] [<8049dbb8>] (rx_submit+0x2c/0x1d4) from [<8049e1c0>] (rx_complete+0x1a4/0x1b8) [127100.245971] [<8049e1c0>] (rx_complete+0x1a4/0x1b8) from [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) [127100.246246] [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) from [<804b887c>] (ehci_urb_done+0xb8/0xc4) [127100.246246] [<804b887c>] (ehci_urb_done+0xb8/0xc4) from [<804bb240>] (qh_completions+0xc8/0x49c) [127100.246307] [<804bb240>] (qh_completions+0xc8/0x49c) from [<804bdcd0>] (scan_async+0x88/0x154) [127100.246398] [<804bdcd0>] (scan_async+0x88/0x154) from [<804be138>] (ehci_work+0x40/0x98) [127100.246398] [<804be138>] (ehci_work+0x40/0x98) from [<804bf9c4>] (ehci_irq+0x33c/0x3a4) [127100.246459] [<804bf9c4>] (ehci_irq+0x33c/0x3a4) from [<804a53ac>] (usb_hcd_irq+0x40/0x50) [127100.246459] [<804a53ac>] (usb_hcd_irq+0x40/0x50) from [<800bf45c>] (handle_irq_event_percpu+0xc4/0x298) [127100.246459] [<800bf45c>] (handle_irq_event_percpu+0xc4/0x298) from [<800bf67c>] (handle_irq_event+0x4c/0x6c) [127100.246459] [<800bf67c>] (handle_irq_event+0x4c/0x6c) from [<800c23b4>] (handle_fasteoi_irq+0xd8/0x124) [127100.246734] [<800c23b4>] (handle_fasteoi_irq+0xd8/0x124) from [<800bedd0>] (generic_handle_irq+0x30/0x40) [127100.246765] [<800bedd0>] (generic_handle_irq+0x30/0x40) from [<800140c4>] (handle_IRQ+0x88/0xc8) [127100.246826] [<800140c4>] (handle_IRQ+0x88/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.246917] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.246917] Exception stack(0x80a47bf8 to 0x80a47c40) [127100.246978] 7be0: 0000000d 00002180 [127100.247009] 7c00: 0000000d 00000005 8bb55040 8236d180 00f7a819 81e00d5a 00000068 80c5ee80 [127100.247100] 7c20: 00000002 80a47c5c 80a47c40 80a47c40 805c734c 805c9a70 80070113 ffffffff [127100.247100] [<806a91c0>] (__irq_svc+0x40/0x70) from [<805c9a70>] (tcp_event_data_recv+0x118/0x194) [127100.247161] [<805c9a70>] (tcp_event_data_recv+0x118/0x194) from [<805cc554>] (tcp_data_queue+0x30c/0x998) [127100.247222] [<805cc554>] (tcp_data_queue+0x30c/0x998) from [<805cfa30>] (tcp_rcv_established+0x668/0x73c) [127100.247222] [<805cfa30>] (tcp_rcv_established+0x668/0x73c) from [<805d684c>] (tcp_v4_do_rcv+0x90/0x220) [127100.247222] [<805d684c>] (tcp_v4_do_rcv+0x90/0x220) from [<805d8bac>] (tcp_v4_rcv+0x550/0x928) [127100.247222] [<805d8bac>] (tcp_v4_rcv+0x550/0x928) from [<805b68e0>] (ip_local_deliver_finish+0x1b0/0x370) [127100.247222] [<805b68e0>] (ip_local_deliver_finish+0x1b0/0x370) from [<805b6c30>] (ip_local_deliver+0x98/0xa8) [127100.247222] [<805b6c30>] (ip_local_deliver+0x98/0xa8) from [<805b670c>] (ip_rcv_finish+0x4b8/0x4dc) [127100.247619] [<805b670c>] (ip_rcv_finish+0x4b8/0x4dc) from [<805b6fd4>] (ip_rcv+0x394/0x414) [127100.247619] [<805b6fd4>] (ip_rcv+0x394/0x414) from [<805832e0>] (__netif_receive_skb+0x4dc/0x550) [127100.247741] [<805832e0>] (__netif_receive_skb+0x4dc/0x550) from [<805833ec>] (process_backlog+0x98/0x168) [127100.247741] [<805833ec>] (process_backlog+0x98/0x168) from [<80586674>] (net_rx_action+0xc8/0x31c) [127100.247741] [<80586674>] (net_rx_action+0xc8/0x31c) from [<8004d28c>] (__do_softirq+0x140/0x27c) [127100.247894] [<8004d28c>] (__do_softirq+0x140/0x27c) from [<8004d864>] (irq_exit+0x58/0xac) [127100.247955] [<8004d864>] (irq_exit+0x58/0xac) from [<800140c8>] (handle_IRQ+0x8c/0xc8) [127100.248016] [<800140c8>] (handle_IRQ+0x8c/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.248077] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.248107] Exception stack(0x80a47f38 to 0x80a47f80) [127100.248107] 7f20: 00000003 00000000 [127100.248168] 7f40: 00000000 8002ce7c 80a46000 80a4e3e0 806b3f50 80a4e290 80ab8988 412fc09a [127100.248199] 7f60: 00000000 80a47f8c 80a47f90 80a47f80 8002b340 8002cea4 60070113 ffffffff [127100.248260] [<806a91c0>] (__irq_svc+0x40/0x70) from [<8002cea4>] (omap_default_idle+0x28/0x2c) [127100.248352] [<8002cea4>] (omap_default_idle+0x28/0x2c) from [<80014630>] (cpu_idle+0x9c/0x104) [127100.248413] [<80014630>] (cpu_idle+0x9c/0x104) from [<8067d648>] (rest_init+0x8c/0xa4) [127100.248474] [<8067d648>] (rest_init+0x8c/0xa4) from [<809d98a8>] (start_kernel+0x2b8/0x314) [127100.248474] Mem-info: [127100.248535] Normal per-cpu: [127100.248535] CPU 0: hi: 186, btch: 31 usd: 181 [127100.248565] CPU 1: hi: 186, btch: 31 usd: 70 [127100.248596] active_anon:21239 inactive_anon:6225 isolated_anon:0 [127100.248657] active_file:52057 inactive_file:111715 isolated_file:0 [127100.248657] unevictable:0 dirty:180 writeback:0 unstable:0 [127100.248687] free:38073 slab_reclaimable:6423 slab_unreclaimable:4248 [127100.248687] mapped:5616 shmem:4706 pagetables:393 bounce:0 [127100.248779] Normal free:152292kB min:8192kB low:10240kB high:12288kB active_anon:84956kB inactive_anon:24900kB active_file:208228kB inactive_file:446860kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1039360kB mlocked:0kB dirty:720kB writeback:0kB mapped:22464kB shmem:18824kB slab_reclaimable:25692kB slab_unreclaimable:16992kB kernel_stack:1056kB pagetables:1572kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [127100.248870] lowmem_reserve[]: 0 0 0 [127100.248870] Normal: 4855*4kB 4831*8kB 4221*16kB 710*32kB 61*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 152228kB [127100.249053] 168490 total pagecache pages [127100.249053] 0 pages in swap cache [127100.249084] Swap cache stats: add 0, delete 0, find 0/0 [127100.249114] Free swap = 1847468kB [127100.249114] Total swap = 1847468kB [127100.291046] 262144 pages of RAM [127100.291076] 38638 free pages [127100.291076] 18477 reserved pages [127100.291107] 10718 slab pages [127100.291137] 158595 pages shared [127100.291137] 0 pages swap cached [127100.291320] swapper/0: page allocation failure: order:3, mode:0x20 [127100.291412] [<8001b8d0>] (unwind_backtrace+0x0/0xec) from [<806905d0>] (dump_stack+0x20/0x24) [127100.291503] [<806905d0>] (dump_stack+0x20/0x24) from [<800fe390>] (warn_alloc_failed+0xfc/0x11c) [127100.291564] [<800fe390>] (warn_alloc_failed+0xfc/0x11c) from [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) [127100.291625] [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) from [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) [127100.291656] [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) from [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) [127100.291717] [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) from [<8069570c>] (cache_alloc_refill+0x21c/0x274) [127100.291778] [<8069570c>] (cache_alloc_refill+0x21c/0x274) from [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) [127100.291839] [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) from [<8057a37c>] (__alloc_skb+0x60/0xfc) [127100.291900] [<8057a37c>] (__alloc_skb+0x60/0xfc) from [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) [127100.291961] [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) from [<8049dbb8>] (rx_submit+0x2c/0x1d4) [127100.292022] [<8049dbb8>] (rx_submit+0x2c/0x1d4) from [<8049e1c0>] (rx_complete+0x1a4/0x1b8) [127100.292083] [<8049e1c0>] (rx_complete+0x1a4/0x1b8) from [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) [127100.292144] [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) from [<804b887c>] (ehci_urb_done+0xb8/0xc4) [127100.292205] [<804b887c>] (ehci_urb_done+0xb8/0xc4) from [<804bb240>] (qh_completions+0xc8/0x49c) [127100.292266] [<804bb240>] (qh_completions+0xc8/0x49c) from [<804bdcd0>] (scan_async+0x88/0x154) [127100.292297] [<804bdcd0>] (scan_async+0x88/0x154) from [<804be138>] (ehci_work+0x40/0x98) [127100.292358] [<804be138>] (ehci_work+0x40/0x98) from [<804bf9c4>] (ehci_irq+0x33c/0x3a4) [127100.292419] [<804bf9c4>] (ehci_irq+0x33c/0x3a4) from [<804a53ac>] (usb_hcd_irq+0x40/0x50) [127100.292480] [<804a53ac>] (usb_hcd_irq+0x40/0x50) from [<800bf45c>] (handle_irq_event_percpu+0xc4/0x298) [127100.292541] [<800bf45c>] (handle_irq_event_percpu+0xc4/0x298) from [<800bf67c>] (handle_irq_event+0x4c/0x6c) [127100.292572] [<800bf67c>] (handle_irq_event+0x4c/0x6c) from [<800c23b4>] (handle_fasteoi_irq+0xd8/0x124) [127100.292633] [<800c23b4>] (handle_fasteoi_irq+0xd8/0x124) from [<800bedd0>] (generic_handle_irq+0x30/0x40) [127100.292724] [<800bedd0>] (generic_handle_irq+0x30/0x40) from [<800140c4>] (handle_IRQ+0x88/0xc8) [127100.292755] [<800140c4>] (handle_IRQ+0x88/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.292816] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.292846] Exception stack(0x80a47bf8 to 0x80a47c40) [127100.292877] 7be0: 0000000d 00002180 [127100.292938] 7c00: 0000000d 00000005 8bb55040 8236d180 00f7a819 81e00d5a 00000068 80c5ee80 [127100.292968] 7c20: 00000002 80a47c5c 80a47c40 80a47c40 805c734c 805c9a70 80070113 ffffffff [127100.293029] [<806a91c0>] (__irq_svc+0x40/0x70) from [<805c9a70>] (tcp_event_data_recv+0x118/0x194) [127100.293090] [<805c9a70>] (tcp_event_data_recv+0x118/0x194) from [<805cc554>] (tcp_data_queue+0x30c/0x998) [127100.293151] [<805cc554>] (tcp_data_queue+0x30c/0x998) from [<805cfa30>] (tcp_rcv_established+0x668/0x73c) [127100.293212] [<805cfa30>] (tcp_rcv_established+0x668/0x73c) from [<805d684c>] (tcp_v4_do_rcv+0x90/0x220) [127100.293273] [<805d684c>] (tcp_v4_do_rcv+0x90/0x220) from [<805d8bac>] (tcp_v4_rcv+0x550/0x928) [127100.293334] [<805d8bac>] (tcp_v4_rcv+0x550/0x928) from [<805b68e0>] (ip_local_deliver_finish+0x1b0/0x370) [127100.293365] [<805b68e0>] (ip_local_deliver_finish+0x1b0/0x370) from [<805b6c30>] (ip_local_deliver+0x98/0xa8) [127100.293426] [<805b6c30>] (ip_local_deliver+0x98/0xa8) from [<805b670c>] (ip_rcv_finish+0x4b8/0x4dc) [127100.293487] [<805b670c>] (ip_rcv_finish+0x4b8/0x4dc) from [<805b6fd4>] (ip_rcv+0x394/0x414) [127100.293548] [<805b6fd4>] (ip_rcv+0x394/0x414) from [<805832e0>] (__netif_receive_skb+0x4dc/0x550) [127100.293609] [<805832e0>] (__netif_receive_skb+0x4dc/0x550) from [<805833ec>] (process_backlog+0x98/0x168) [127100.293640] [<805833ec>] (process_backlog+0x98/0x168) from [<80586674>] (net_rx_action+0xc8/0x31c) [127100.293701] [<80586674>] (net_rx_action+0xc8/0x31c) from [<8004d28c>] (__do_softirq+0x140/0x27c) [127100.293762] [<8004d28c>] (__do_softirq+0x140/0x27c) from [<8004d864>] (irq_exit+0x58/0xac) [127100.293823] [<8004d864>] (irq_exit+0x58/0xac) from [<800140c8>] (handle_IRQ+0x8c/0xc8) [127100.293884] [<800140c8>] (handle_IRQ+0x8c/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.293914] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.293945] Exception stack(0x80a47f38 to 0x80a47f80) [127100.293975] 7f20: 00000003 00000000 [127100.294036] 7f40: 00000000 8002ce7c 80a46000 80a4e3e0 806b3f50 80a4e290 80ab8988 412fc09a [127100.294067] 7f60: 00000000 80a47f8c 80a47f90 80a47f80 8002b340 8002cea4 60070113 ffffffff [127100.294128] [<806a91c0>] (__irq_svc+0x40/0x70) from [<8002cea4>] (omap_default_idle+0x28/0x2c) [127100.294189] [<8002cea4>] (omap_default_idle+0x28/0x2c) from [<80014630>] (cpu_idle+0x9c/0x104) [127100.294250] [<80014630>] (cpu_idle+0x9c/0x104) from [<8067d648>] (rest_init+0x8c/0xa4) [127100.294311] [<8067d648>] (rest_init+0x8c/0xa4) from [<809d98a8>] (start_kernel+0x2b8/0x314) [127100.294342] Mem-info: [127100.294342] Normal per-cpu: [127100.294372] CPU 0: hi: 186, btch: 31 usd: 181 [127100.294403] CPU 1: hi: 186, btch: 31 usd: 54 [127100.294464] active_anon:21239 inactive_anon:6225 isolated_anon:0 [127100.294464] active_file:52057 inactive_file:111715 isolated_file:0 [127100.294494] unevictable:0 dirty:180 writeback:0 unstable:0 [127100.294494] free:38073 slab_reclaimable:6423 slab_unreclaimable:4265 [127100.294525] mapped:5616 shmem:4706 pagetables:393 bounce:0 [127100.294586] Normal free:152292kB min:8192kB low:10240kB high:12288kB active_anon:84956kB inactive_anon:24900kB active_file:208228kB inactive_file:446860kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1039360kB mlocked:0kB dirty:720kB writeback:0kB mapped:22464kB shmem:18824kB slab_reclaimable:25692kB slab_unreclaimable:17060kB kernel_stack:1056kB pagetables:1572kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [127100.294677] lowmem_reserve[]: 0 0 0 [127100.294738] Normal: 4855*4kB 4831*8kB 4221*16kB 710*32kB 61*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 152228kB [127100.294860] 168490 total pagecache pages [127100.294860] 0 pages in swap cache [127100.294891] Swap cache stats: add 0, delete 0, find 0/0 [127100.294921] Free swap = 1847468kB [127100.294921] Total swap = 1847468kB [127100.336883] 262144 pages of RAM [127100.336883] 38638 free pages [127100.336914] 18477 reserved pages [127100.336944] 10718 slab pages [127100.336944] 158595 pages shared [127100.336975] 0 pages swap cached
<snip>
[127100.664459] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.672088] swapper/0: page allocation failure: order:3, mode:0x20 [127100.672149] [<8001b8d0>] (unwind_backtrace+0x0/0xec) from [<806905d0>] (dump_stack+0x20/0x24) [127100.672210] [<806905d0>] (dump_stack+0x20/0x24) from [<800fe390>] (warn_alloc_failed+0xfc/0x11c) [127100.672210] [<800fe390>] (warn_alloc_failed+0xfc/0x11c) from [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) [127100.672363] [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) from [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) [127100.672393] [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) from [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) [127100.672485] [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) from [<8069570c>] (cache_alloc_refill+0x21c/0x274) [127100.672485] [<8069570c>] (cache_alloc_refill+0x21c/0x274) from [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) [127100.672576] [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) from [<8057a37c>] (__alloc_skb+0x60/0xfc) [127100.672637] [<8057a37c>] (__alloc_skb+0x60/0xfc) from [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) [127100.672698] [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) from [<8049dbb8>] (rx_submit+0x2c/0x1d4) [127100.672821] [<8049dbb8>] (rx_submit+0x2c/0x1d4) from [<8049e89c>] (usbnet_bh+0x1b8/0x258) [127100.672821] [<8049e89c>] (usbnet_bh+0x1b8/0x258) from [<8004cbc4>] (tasklet_action+0xb0/0x1ac) [127100.672821] [<8004cbc4>] (tasklet_action+0xb0/0x1ac) from [<8004d28c>] (__do_softirq+0x140/0x27c) [127100.672973] [<8004d28c>] (__do_softirq+0x140/0x27c) from [<8004d864>] (irq_exit+0x58/0xac) [127100.673034] [<8004d864>] (irq_exit+0x58/0xac) from [<800140c8>] (handle_IRQ+0x8c/0xc8) [127100.673095] [<800140c8>] (handle_IRQ+0x8c/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.673156] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.673187] Exception stack(0x80a47f38 to 0x80a47f80) [127100.673187] 7f20: 00000003 00000000 [127100.673248] 7f40: 00000000 8002ce7c 80a46000 80a4e3e0 806b3f50 80a4e290 80ab8988 412fc09a [127100.673278] 7f60: 00000000 80a47f8c 80a47f90 80a47f80 8002b340 8002cea4 60070113 ffffffff [127100.673278] [<806a91c0>] (__irq_svc+0x40/0x70) from [<8002cea4>] (omap_default_idle+0x28/0x2c) [127100.673431] [<8002cea4>] (omap_default_idle+0x28/0x2c) from [<80014630>] (cpu_idle+0x9c/0x104) [127100.673492] [<80014630>] (cpu_idle+0x9c/0x104) from [<8067d648>] (rest_init+0x8c/0xa4) [127100.673553] [<8067d648>] (rest_init+0x8c/0xa4) from [<809d98a8>] (start_kernel+0x2b8/0x314) [127100.673553] Mem-info: [127100.673614] Normal per-cpu: [127100.673614] CPU 0: hi: 186, btch: 31 usd: 181 [127100.673614] CPU 1: hi: 186, btch: 31 usd: 45 [127100.673675] active_anon:21307 inactive_anon:6225 isolated_anon:0 [127100.673736] active_file:52057 inactive_file:111732 isolated_file:0 [127100.673736] unevictable:0 dirty:205 writeback:0 unstable:0 [127100.673767] free:37608 slab_reclaimable:6423 slab_unreclaimable:4639 [127100.673767] mapped:5616 shmem:4706 pagetables:393 bounce:0 [127100.673828] Normal free:150432kB min:8192kB low:10240kB high:12288kB active_anon:85228kB inactive_anon:24900kB active_file:208228kB inactive_file:446928kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1039360kB mlocked:0kB dirty:820kB writeback:0kB mapped:22464kB shmem:18824kB slab_reclaimable:25692kB slab_unreclaimable:18556kB kernel_stack:1056kB pagetables:1572kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [127100.673889] lowmem_reserve[]: 0 0 0 [127100.673889] Normal: 4670*4kB 4691*8kB 4221*16kB 710*32kB 61*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 150368kB [127100.674102] 168515 total pagecache pages [127100.674133] 0 pages in swap cache [127100.674163] Swap cache stats: add 0, delete 0, find 0/0 [127100.674163] Free swap = 1847468kB [127100.674163] Total swap = 1847468kB [127100.716339] 262144 pages of RAM [127100.716369] 38162 free pages [127100.716369] 18477 reserved pages [127100.716400] 11086 slab pages [127100.716430] 158642 pages shared [127100.716430] 0 pages swap cached [127100.716674] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.724212] swapper/0: page allocation failure: order:3, mode:0x20 [127100.724304] [<8001b8d0>] (unwind_backtrace+0x0/0xec) from [<806905d0>] (dump_stack+0x20/0x24) [127100.724395] [<806905d0>] (dump_stack+0x20/0x24) from [<800fe390>] (warn_alloc_failed+0xfc/0x11c) [127100.724395] [<800fe390>] (warn_alloc_failed+0xfc/0x11c) from [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) [127100.724395] [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) from [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) [127100.724395] [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) from [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) [127100.724395] [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) from [<8069570c>] (cache_alloc_refill+0x21c/0x274) [127100.724395] [<8069570c>] (cache_alloc_refill+0x21c/0x274) from [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) [127100.724395] [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) from [<8057a37c>] (__alloc_skb+0x60/0xfc) [127100.724761] [<8057a37c>] (__alloc_skb+0x60/0xfc) from [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) [127100.724822] [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) from [<8049dbb8>] (rx_submit+0x2c/0x1d4) [127100.724822] [<8049dbb8>] (rx_submit+0x2c/0x1d4) from [<8049e89c>] (usbnet_bh+0x1b8/0x258) [127100.724822] [<8049e89c>] (usbnet_bh+0x1b8/0x258) from [<8004cbc4>] (tasklet_action+0xb0/0x1ac) [127100.724822] [<8004cbc4>] (tasklet_action+0xb0/0x1ac) from [<8004d28c>] (__do_softirq+0x140/0x27c) [127100.724822] [<8004d28c>] (__do_softirq+0x140/0x27c) from [<8004d864>] (irq_exit+0x58/0xac) [127100.724822] [<8004d864>] (irq_exit+0x58/0xac) from [<800140c8>] (handle_IRQ+0x8c/0xc8) [127100.725219] [<800140c8>] (handle_IRQ+0x8c/0xc8) from [<800086d8>] (gic_handle_irq+0x80/0xac) [127100.725280] [<800086d8>] (gic_handle_irq+0x80/0xac) from [<806a91c0>] (__irq_svc+0x40/0x70) [127100.725280] Exception stack(0x80a47f38 to 0x80a47f80) [127100.725341] 7f20: 00000003 00000000 [127100.725402] 7f40: 00000000 8002ce7c 80a46000 80a4e3e0 806b3f50 80a4e290 80ab8988 412fc09a [127100.725433] 7f60: 00000000 80a47f8c 80a47f90 80a47f80 8002b340 8002cea4 60070113 ffffffff [127100.725433] [<806a91c0>] (__irq_svc+0x40/0x70) from [<8002cea4>] (omap_default_idle+0x28/0x2c) [127100.725555] [<8002cea4>] (omap_default_idle+0x28/0x2c) from [<80014630>] (cpu_idle+0x9c/0x104) [127100.725616] [<80014630>] (cpu_idle+0x9c/0x104) from [<8067d648>] (rest_init+0x8c/0xa4) [127100.725677] [<8067d648>] (rest_init+0x8c/0xa4) from [<809d98a8>] (start_kernel+0x2b8/0x314) [127100.725677] Mem-info: [127100.725677] Normal per-cpu: [127100.725738] CPU 0: hi: 186, btch: 31 usd: 181 [127100.725769] CPU 1: hi: 186, btch: 31 usd: 72 [127100.725830] active_anon:21307 inactive_anon:6225 isolated_anon:0 [127100.725860] active_file:52057 inactive_file:111732 isolated_file:0 [127100.725860] unevictable:0 dirty:205 writeback:0 unstable:0 [127100.725860] free:37577 slab_reclaimable:6423 slab_unreclaimable:4639 [127100.725891] mapped:5616 shmem:4706 pagetables:393 bounce:0 [127100.725982] Normal free:150308kB min:8192kB low:10240kB high:12288kB active_anon:85228kB inactive_anon:24900kB active_file:208228kB inactive_file:446928kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1039360kB mlocked:0kB dirty:820kB writeback:0kB mapped:22464kB shmem:18824kB slab_reclaimable:25692kB slab_unreclaimable:18556kB kernel_stack:1056kB pagetables:1572kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no [127100.726043] lowmem_reserve[]: 0 0 0 [127100.726104] Normal: 4639*4kB 4691*8kB 4221*16kB 710*32kB 61*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 150244kB [127100.726226] 168515 total pagecache pages [127100.726226] 0 pages in swap cache [127100.726257] Swap cache stats: add 0, delete 0, find 0/0 [127100.726287] Free swap = 1847468kB [127100.726318] Total swap = 1847468kB [127100.767608] 262144 pages of RAM [127100.767639] 38160 free pages [127100.767669] 18477 reserved pages [127100.767669] 11086 slab pages [127100.767700] 158646 pages shared [127100.767700] 0 pages swap cached [127100.767944] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.775512] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.783050] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.790588] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.798065] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped [127100.805541] smsc95xx 1-1.1:1.0: eth0: kevent 2 may have been dropped
On 06/28/12 11:27, the mail apparently from Tom Gall included:
Hi All,
I'm stressing a system with apachebench. As one scales up work on a system obviously there's always a point where the wheels fall off, the engine explodes or something else exciting happens. But as Han Solo would say ... "hold together baby....", I'd like to eek out as much as I can. (If you're really interested, here's what I'm up to : http://fullshovel.wordpress.com/ start with part 1)
In this case with apachebench, I'm geting the following allocation errors in the kernel and need a little help deciphering. It sure looks like there's plenty of space to swap out however if I have this right, we're getting so much network traffic that the kernel gets inundated and it OOMs in the network stack.
I did later try setting sysctl -w vm.min_free_kbytes=32768 but that didn't really seem to help.
The much more complete dmesg dump is located at http://people.linaro.org/~tgall/dmesg-dump.txt
[127100.245117] swapper/0: page allocation failure: order:3, mode:0x20
[127100.245666] [<80100f14>] (__alloc_pages_nodemask+0x678/0x7a4) from [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) [127100.245666] [<80695270>] (kmem_getpages.isra.35+0x3c/0xc0) from [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) [127100.245666] [<80695380>] (cache_grow.constprop.37+0x8c/0x1fc) from [<8069570c>] (cache_alloc_refill+0x21c/0x274) [127100.245819] [<8069570c>] (cache_alloc_refill+0x21c/0x274) from [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) [127100.245910] [<80132dac>] (__kmalloc_track_caller+0xac/0x1b0) from [<8057a37c>] (__alloc_skb+0x60/0xfc) [127100.245971] [<8057a37c>] (__alloc_skb+0x60/0xfc) from [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) [127100.245971] [<8057a874>] (__netdev_alloc_skb+0x2c/0x54) from [<8049dbb8>] (rx_submit+0x2c/0x1d4) [127100.245971] [<8049dbb8>] (rx_submit+0x2c/0x1d4) from [<8049e1c0>] (rx_complete+0x1a4/0x1b8) [127100.245971] [<8049e1c0>] (rx_complete+0x1a4/0x1b8) from [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) [127100.246246] [<804a5f38>] (usb_hcd_giveback_urb+0xb0/0xfc) from [<804b887c>] (ehci_urb_done+0xb8/0xc4) [127100.246246] [<804b887c>] (ehci_urb_done+0xb8/0xc4) from [<804bb240>] (qh_completions+0xc8/0x49c)
Just some not directly useful extra info...
I noticed these yesterday in dmesg as well while adding the 32K min_free_kybytes in tilt-3.4 as a hack. It seems to be part of some syndrome with smsc driver and network memory allocation that's in mainline and not Panda-specific. Yesterday I saw in Google the same problems plaguing Raspberry Pi folks.
When I recently tried to stress the Panda a week or so ago by cloning gcc with a plan to compile it, in fact it lost sanity during the download with a storm of these kevent lost messages, hence the 32K hack being added.
I also remember the same problems about kevents being dropped getting looked at like a year ago without any solid result, it'll be interesting if anyone understands and can explain what the underlying issue is.
-Andy