баг системы или nginx?

Sun Oct 14 09:49:28 UTC 2012

#cat /var/log/messages|grep _continuous_flood_|wc -l
15

#uname -a
Linux node2c 3.1.0-1.2-xen #5 SMP Mon Mar 5 16:41:01 MSK 2012 x86_64
GNU/Linux

# cat /etc/debian_version
6.0.5


Oct 14 01:11:01 node2c kernel: [1365882.441751] The following is only an
harmless informational message.
Oct 14 01:11:01 node2c kernel: [1365882.441756] Unless you get a
_continuous_flood_ of these messages it means
Oct 14 01:11:01 node2c kernel: [1365882.441762] everything is working fine.
Allocations from irqs cannot be
Oct 14 01:11:01 node2c kernel: [1365882.441767] perfectly reliable and the
kernel is designed to handle that.
Oct 14 01:11:01 node2c kernel: [1365882.441773] nginx: page allocation
failure. order:1, mode:0x20
Oct 14 01:11:01 node2c kernel: [1365882.441779] Pid: 20800, comm: nginx Not
tainted 3.1.0-1.2-xen #5
Oct 14 01:11:01 node2c kernel: [1365882.441784] Call Trace:
Oct 14 01:11:01 node2c kernel: [1365882.441804]  [<ffffffff800082a5>]
dump_trace+0x85/0x1c0
Oct 14 01:11:01 node2c kernel: [1365882.441818]  [<ffffffff804f14c0>]
dump_stack+0x69/0x6f
Oct 14 01:11:01 node2c kernel: [1365882.441843]  [<ffffffff800d79ea>]
warn_alloc_failed+0xfa/0x190
Oct 14 01:11:01 node2c kernel: [1365882.441853]  [<ffffffff800db26c>]
__alloc_pages_nodemask+0x6ac/0x820
Oct 14 01:11:01 node2c kernel: [1365882.441863]  [<ffffffff804f5ef6>]
kmem_getpages.isra.45+0x2b/0xcf
Oct 14 01:11:01 node2c kernel: [1365882.441871]  [<ffffffff804f60e0>]
cache_grow.constprop.49+0xb7/0x21c
Oct 14 01:11:01 node2c kernel: [1365882.441878]  [<ffffffff804f63f7>]
cache_alloc_refill+0x1b2/0x202
Oct 14 01:11:01 node2c kernel: [1365882.441887]  [<ffffffff80110f57>]
kmem_cache_alloc+0x157/0x160
Oct 14 01:11:01 node2c kernel: [1365882.441897]  [<ffffffff803e1ff3>]
sk_prot_alloc+0x43/0x200
Oct 14 01:11:01 node2c kernel: [1365882.441906]  [<ffffffff803e26da>]
sk_clone+0x1a/0x300
Oct 14 01:11:01 node2c kernel: [1365882.441915]  [<ffffffff8042f110>]
inet_csk_clone+0x10/0xc0
Oct 14 01:11:01 node2c kernel: [1365882.441926]  [<ffffffff804477b1>]
tcp_create_openreq_child+0x21/0x460
Oct 14 01:11:01 node2c kernel: [1365882.441935]  [<ffffffff80445d37>]
tcp_v4_syn_recv_sock+0x47/0x280
Oct 14 01:11:01 node2c kernel: [1365882.441942]  [<ffffffff8044834f>]
tcp_check_req+0x2ff/0x4c0
Oct 14 01:11:01 node2c kernel: [1365882.441950]  [<ffffffff80444faa>]
tcp_v4_hnd_req+0x6a/0x130
Oct 14 01:11:01 node2c kernel: [1365882.441957]  [<ffffffff80445a33>]
tcp_v4_do_rcv+0x123/0x1d0
Oct 14 01:11:01 node2c kernel: [1365882.441964]  [<ffffffff80447239>]
tcp_v4_rcv+0x559/0x810
Oct 14 01:11:01 node2c kernel: [1365882.441972]  [<ffffffff8042461c>]
ip_local_deliver_finish+0xcc/0x270
Oct 14 01:11:01 node2c kernel: [1365882.441983]  [<ffffffff803f3e72>]
__netif_receive_skb+0x502/0x5b0
Oct 14 01:11:01 node2c kernel: [1365882.441992]  [<ffffffff803f3fdf>]
process_backlog+0xbf/0x200
Oct 14 01:11:01 node2c kernel: [1365882.442000]  [<ffffffff803f4d21>]
net_rx_action+0x151/0x2d0
Oct 14 01:11:01 node2c kernel: [1365882.442011]  [<ffffffff80048faa>]
__do_softirq+0xba/0x230
Oct 14 01:11:01 node2c kernel: [1365882.442021]  [<ffffffff8050f5cc>]
call_softirq+0x1c/0x30
Oct 14 01:11:01 node2c kernel: [1365882.442029]  [<ffffffff800081e5>]
do_softirq+0x95/0xd0
Oct 14 01:11:01 node2c kernel: [1365882.442037]  [<ffffffff80048514>]
local_bh_enable+0x94/0xa0
Oct 14 01:11:01 node2c kernel: [1365882.442044]  [<ffffffff803f5edb>]
dev_queue_xmit+0x18b/0x490
Oct 14 01:11:01 node2c kernel: [1365882.442052]  [<ffffffff80440a9c>]
tcp_transmit_skb+0x31c/0x570
Oct 14 01:11:01 node2c kernel: [1365882.442059]  [<ffffffff804415a5>]
tcp_write_xmit+0x1a5/0x3a0
Oct 14 01:11:01 node2c kernel: [1365882.442067]  [<ffffffff804417e9>]
__tcp_push_pending_frames+0x19/0xb0
Oct 14 01:11:01 node2c kernel: [1365882.442074]  [<ffffffff80432e87>]
tcp_sendmsg+0x897/0xd10
Oct 14 01:11:01 node2c kernel: [1365882.442082]  [<ffffffff803dd5d9>]
do_sock_write.isra.10+0xc9/0xf0
Oct 14 01:11:01 node2c kernel: [1365882.442090]  [<ffffffff803dd690>]
sock_aio_write+0x90/0xc0
Oct 14 01:11:01 node2c kernel: [1365882.442096]  [<ffffffff8011f17d>]
do_sync_readv_writev+0xad/0xf0
Oct 14 01:11:01 node2c kernel: [1365882.442101]  [<ffffffff8011f468>]
do_readv_writev+0xd8/0x200
Oct 14 01:11:01 node2c kernel: [1365882.442105]  [<ffffffff8011f73b>]
sys_writev+0x4b/0xc0
Oct 14 01:11:01 node2c kernel: [1365882.442110]  [<ffffffff8050eb33>]
system_call_fastpath+0x16/0x1b
Oct 14 01:11:01 node2c kernel: [1365882.442118]  [<00007f432e4d77db>]
0x7f432e4d77da
Oct 14 01:11:01 node2c kernel: [1365882.442120] Mem-Info:
Oct 14 01:11:01 node2c kernel: [1365882.442123] DMA per-cpu:
Oct 14 01:11:01 node2c kernel: [1365882.442125] CPU    0: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442127] CPU    1: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442130] CPU    2: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442132] CPU    3: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442135] CPU    4: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442137] CPU    5: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442140] CPU    6: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442142] CPU    7: hi:    0, btch:  
1 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442144] DMA32 per-cpu:
Oct 14 01:11:01 node2c kernel: [1365882.442147] CPU    0: hi:  155, btch: 
38 usd: 106
Oct 14 01:11:01 node2c kernel: [1365882.442149] CPU    1: hi:  155, btch: 
38 usd:  76
Oct 14 01:11:01 node2c kernel: [1365882.442152] CPU    2: hi:  155, btch: 
38 usd:  54
Oct 14 01:11:01 node2c kernel: [1365882.442154] CPU    3: hi:  155, btch: 
38 usd: 150
Oct 14 01:11:01 node2c kernel: [1365882.442157] CPU    4: hi:  155, btch: 
38 usd: 159
Oct 14 01:11:01 node2c kernel: [1365882.442159] CPU    5: hi:  155, btch: 
38 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442162] CPU    6: hi:  155, btch: 
38 usd:  38
Oct 14 01:11:01 node2c kernel: [1365882.442164] CPU    7: hi:  155, btch: 
38 usd: 134
Oct 14 01:11:01 node2c kernel: [1365882.442166] Normal per-cpu:
Oct 14 01:11:01 node2c kernel: [1365882.442169] CPU    0: hi:   35, btch:  
8 usd:  32
Oct 14 01:11:01 node2c kernel: [1365882.442171] CPU    1: hi:   35, btch:  
8 usd:  20
Oct 14 01:11:01 node2c kernel: [1365882.442174] CPU    2: hi:   35, btch:  
8 usd:  16
Oct 14 01:11:01 node2c kernel: [1365882.442176] CPU    3: hi:   35, btch:  
8 usd:  16
Oct 14 01:11:01 node2c kernel: [1365882.442179] CPU    4: hi:   35, btch:  
8 usd:  30
Oct 14 01:11:01 node2c kernel: [1365882.442181] CPU    5: hi:   35, btch:  
8 usd:   0
Oct 14 01:11:01 node2c kernel: [1365882.442183] CPU    6: hi:   35, btch:  
8 usd:  10
Oct 14 01:11:01 node2c kernel: [1365882.442186] CPU    7: hi:   35, btch:  
8 usd:  16
Oct 14 01:11:01 node2c kernel: [1365882.442191] active_anon:12676
inactive_anon:12081 isolated_anon:0
Oct 14 01:11:01 node2c kernel: [1365882.442192]  active_file:27944
inactive_file:27975 isolated_file:0
Oct 14 01:11:01 node2c kernel: [1365882.442192]  unevictable:0 dirty:71
writeback:0 unstable:0
Oct 14 01:11:01 node2c kernel: [1365882.442193]  free:7655
slab_reclaimable:5465 slab_unreclaimable:5143
Oct 14 01:11:01 node2c kernel: [1365882.442194]  mapped:2884 shmem:222
pagetables:0 bounce:0
Oct 14 01:11:01 node2c kernel: [1365882.442203] DMA free:2320kB min:72kB
low:88kB high:108kB active_anon:0kB inactive_anon:0kB active_file:0kB
inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB
present:14580kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB
slab_reclaimable:540kB slab_unreclaimable:1476kB kernel_stack:96kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? yes
Oct 14 01:11:01 node2c kernel: [1365882.442210] lowmem_reserve[]: 0 571 571
571
Oct 14 01:11:01 node2c kernel: [1365882.442219] DMA32 free:27684kB
min:2444kB low:3052kB high:3664kB active_anon:25776kB inactive_anon:23448kB
active_file:111768kB inactive_file:111868kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:509620kB mlocked:0kB
dirty:280kB writeback:0kB mapped:10644kB shmem:0kB slab_reclaimable:16720kB
slab_unreclaimable:15452kB kernel_stack:1056kB pagetables:0kB unstable:0kB
bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Oct 14 01:11:01 node2c kernel: [1365882.442227] lowmem_reserve[]: 0 0 0 0
Oct 14 01:11:01 node2c kernel: [1365882.442235] Normal free:616kB min:576kB
low:720kB high:864kB active_anon:24928kB inactive_anon:24876kB
active_file:8kB inactive_file:32kB unevictable:0kB isolated(anon):0kB
isolated(file):0kB present:64096kB mlocked:0kB dirty:4kB writeback:0kB
mapped:888kB shmem:888kB slab_reclaimable:4600kB slab_unreclaimable:3644kB
kernel_stack:168kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
Oct 14 01:11:01 node2c kernel: [1365882.442242] lowmem_reserve[]: 0 0 0 0
Oct 14 01:11:01 node2c kernel: [1365882.442247] DMA: 180*4kB 1*8kB 1*16kB
0*32kB 1*64kB 0*128kB 0*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 2344kB
Oct 14 01:11:01 node2c kernel: [1365882.442259] DMA32: 6909*4kB 0*8kB 0*16kB
0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 27636kB
Oct 14 01:11:01 node2c kernel: [1365882.442271] Normal: 124*4kB 15*8kB
0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB =
616kB
Oct 14 01:11:01 node2c kernel: [1365882.442282] 59192 total pagecache pages
Oct 14 01:11:01 node2c kernel: [1365882.442285] 3039 pages in swap cache
Oct 14 01:11:01 node2c kernel: [1365882.442287] Swap cache stats: add
7599771, delete 7596732, find 15846114/16819522
Oct 14 01:11:01 node2c kernel: [1365882.442290] Free swap  = 1855692kB
Oct 14 01:11:01 node2c kernel: [1365882.442291] Total swap = 1998844kB
Oct 14 01:11:01 node2c kernel: [1365882.445607] 2097152 pages RAM
Oct 14 01:11:01 node2c kernel: [1365882.445607] 1992172 pages reserved
Oct 14 01:11:01 node2c kernel: [1365882.445607] 24673 pages shared
Oct 14 01:11:01 node2c kernel: [1365882.445607] 79768 pages non-shared

Posted at Nginx Forum: http://forum.nginx.org/read.php?21,231770,231770#msg-231770