LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* I have a blaze of 353 page allocation failures, all alike
@ 2011-02-10 15:03 Peter Kruse
  2011-02-14 16:49 ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-10 15:03 UTC (permalink / raw)
  To: linux-kernel

[-- Attachment #1: Type: text/plain, Size: 1017 bytes --]

Hello,

today one of our servers went berserk and produced literally 353
page allocation failures in 7 minutes until it was reset
(sysrq was still working).  I attach one of them as an example.
The failures happened for different processes ranging from
sshd, top, java, tclsh, ypserv, smbd, portmap, kswapd to Xvnc4.
I already reported about an incidence with this server here:
https://lkml.org/lkml/2011/1/19/145
we have set vm.min_free_kbytes = 2097152 but the problem
obviously did not go away.
All traces start with one of these three beginnings:

Call Trace:
  <IRQ>  [<ffffffff81071f46>] __alloc_pages_nodemask+0x5ca/0x600
  [<ffffffff81344127>] ? skb_dma_map+0xd2/0x23f

Call Trace:
  <IRQ>  [<ffffffff81071f46>] __alloc_pages_nodemask+0x5ca/0x600
  [<ffffffff8109428b>] kmem_getpages+0x5c/0x127

Call Trace:
  <IRQ>  [<ffffffff81071f46>] __alloc_pages_nodemask+0x5ca/0x600
  [<ffffffffa01418fd>] ? tcp_packet+0xc87/0xcb2 [nf_conntrack]

Please anybody, what is the cause of these failures?

Thanks,

   Peter

[-- Attachment #2: calltrace.1 --]
[-- Type: text/plain, Size: 2896 bytes --]

Call Trace:
 <IRQ>  [<ffffffff81071f46>] __alloc_pages_nodemask+0x5ca/0x600
 [<ffffffff8109428b>] kmem_getpages+0x5c/0x127
 [<ffffffff81094475>] fallback_alloc+0x11f/0x195
 [<ffffffff81094614>] ____cache_alloc_node+0x129/0x138
 [<ffffffff81094fdd>] kmem_cache_alloc+0xd1/0xfe
 [<ffffffff8133c2f9>] sk_prot_alloc+0x2c/0xcd
 [<ffffffff8133c427>] sk_clone+0x1b/0x24b
 [<ffffffff81369ce2>] inet_csk_clone+0x13/0x81
 [<ffffffff8137d698>] tcp_create_openreq_child+0x1d/0x39c
 [<ffffffff8137c309>] tcp_v4_syn_recv_sock+0x57/0x1bc
 [<ffffffff8137d50f>] tcp_check_req+0x210/0x37c
 [<ffffffffa0154423>] ? ipv4_confirm+0x161/0x179 [nf_conntrack_ipv4]
 [<ffffffff8137ba63>] tcp_v4_do_rcv+0xc1/0x1d7
 [<ffffffff8137c021>] tcp_v4_rcv+0x4a8/0x739
 [<ffffffff8135ba27>] ? nf_hook_slow+0x63/0xc3
 [<ffffffff81361bb0>] ? ip_local_deliver_finish+0x0/0x1d0
 [<ffffffff81361ca8>] ip_local_deliver_finish+0xf8/0x1d0
 [<ffffffff81361df2>] ip_local_deliver+0x72/0x7a
 [<ffffffff813618ac>] ip_rcv_finish+0x33c/0x356
 [<ffffffff81361b79>] ip_rcv+0x2b3/0x2ea
 [<ffffffff813a2861>] ? packet_rcv_spkt+0x10f/0x11a
 [<ffffffff8134660a>] netif_receive_skb+0x2cb/0x2ed
 [<ffffffff81346767>] napi_skb_finish+0x28/0x40
 [<ffffffff81346ba5>] napi_gro_receive+0x2a/0x2f
 [<ffffffffa001669d>] igb_poll+0x507/0x86a [igb]
 [<ffffffffa0015ef8>] ? igb_clean_tx_irq+0x1dd/0x47b [igb]
 [<ffffffff81346cb6>] net_rx_action+0xa7/0x178
 [<ffffffff8103bd21>] __do_softirq+0x96/0x119
 [<ffffffff8100bf5c>] call_softirq+0x1c/0x28
 [<ffffffff8100d9e7>] do_softirq+0x33/0x6b
 [<ffffffff8103b844>] irq_exit+0x36/0x38
 [<ffffffff8100d0e9>] do_IRQ+0xa3/0xba
 [<ffffffff8100b7d3>] ret_from_intr+0x0/0xa
 <EOI>  [<ffffffffa00f046f>] ? xfs_reclaim_inode_shrink+0xc3/0x112 [xfs]
 [<ffffffffa00f0451>] ? xfs_reclaim_inode_shrink+0xa5/0x112 [xfs]
 [<ffffffffa00f04bd>] ? xfs_reclaim_inode_shrink+0x111/0x112 [xfs]
 [<ffffffff810770fc>] ? shrink_slab+0xd2/0x154
 [<ffffffff81077e00>] ? try_to_free_pages+0x221/0x31c
 [<ffffffff81074f4a>] ? isolate_pages_global+0x0/0x1f0
 [<ffffffff81071d79>] ? __alloc_pages_nodemask+0x3fd/0x600
 [<ffffffff8109428b>] ? kmem_getpages+0x5c/0x127
 [<ffffffff81094475>] ? fallback_alloc+0x11f/0x195
 [<ffffffff81094614>] ? ____cache_alloc_node+0x129/0x138
 [<ffffffff810a9055>] ? pollwake+0x0/0x5b
 [<ffffffff810946bf>] ? kmem_cache_alloc_node+0x9c/0xc7
 [<ffffffff8109472d>] ? __kmalloc_node+0x43/0x45
 [<ffffffff81340625>] ? __alloc_skb+0x6b/0x164
 [<ffffffff8133bcc1>] ? sock_alloc_send_pskb+0xdd/0x31c
 [<ffffffff8133bf10>] ? sock_alloc_send_skb+0x10/0x12
 [<ffffffff8139e4c2>] ? unix_stream_sendmsg+0x180/0x312
 [<ffffffff81338270>] ? sock_aio_write+0x109/0x122
 [<ffffffff8100b7ce>] ? common_interrupt+0xe/0x13
 [<ffffffff8109a41a>] ? do_sync_write+0xe7/0x12d
 [<ffffffff81049208>] ? autoremove_wake_function+0x0/0x38
 [<ffffffff8100b7ce>] ? common_intreclaimable:78357
 mapped:11679 shmem:26799 pagetables:13497 bounce:0

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-10 15:03 I have a blaze of 353 page allocation failures, all alike Peter Kruse
@ 2011-02-14 16:49 ` Christoph Lameter
  2011-02-15  7:44   ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-02-14 16:49 UTC (permalink / raw)
  To: Peter Kruse; +Cc: linux-kernel

On Thu, 10 Feb 2011, Peter Kruse wrote:

> today one of our servers went berserk and produced literally 353
> page allocation failures in 7 minutes until it was reset
> (sysrq was still working).  I attach one of them as an example.
> The failures happened for different processes ranging from
> sshd, top, java, tclsh, ypserv, smbd, portmap, kswapd to Xvnc4.
> I already reported about an incidence with this server here:
> https://lkml.org/lkml/2011/1/19/145

Atomic allocations are failing there? gfpmask = 0x20?

> we have set vm.min_free_kbytes = 2097152 but the problem
> obviously did not go away.

2GB of reserves? How much memory does your system have?

> Please anybody, what is the cause of these failures?

Could you post the entire messages from the kernel log? We need the OOM
info to figure out more about the problem.


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-14 16:49 ` Christoph Lameter
@ 2011-02-15  7:44   ` Peter Kruse
  2011-02-15 17:30     ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-15  7:44 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: linux-kernel

[-- Attachment #1: Type: text/plain, Size: 1059 bytes --]

Hi Christoph,

thanks for your response

Christoph Lameter wrote:
> On Thu, 10 Feb 2011, Peter Kruse wrote:
> 
>> today one of our servers went berserk and produced literally 353
>> page allocation failures in 7 minutes until it was reset
>> (sysrq was still working).  I attach one of them as an example.
>> The failures happened for different processes ranging from
>> sshd, top, java, tclsh, ypserv, smbd, portmap, kswapd to Xvnc4.
>> I already reported about an incidence with this server here:
>> https://lkml.org/lkml/2011/1/19/145
> 
> Atomic allocations are failing there? gfpmask = 0x20?
> 
>> we have set vm.min_free_kbytes = 2097152 but the problem
>> obviously did not go away.
> 
> 2GB of reserves? How much memory does your system have?

48GB

> 
>> Please anybody, what is the cause of these failures?
> 
> Could you post the entire messages from the kernel log? We need the OOM
> info to figure out more about the problem.
> 

I attach one of the call traces, or would it be better if I send the
kern.log (about 6MB)?

Best regards,

   Peter

[-- Attachment #2: calltrace1 --]
[-- Type: text/plain, Size: 9749 bytes --]

Feb 10 11:59:49 beosrv1-t kernel: [1968909.359343] ssh: page allocation failure. order:1, mode:0x20
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359363] Pid: 12985, comm: ssh Not tainted 2.6.32.23-ql-server-14 #1
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359381] Call Trace:
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359390]  <IRQ>  [<ffffffff81071f46>] __alloc_pages_nodemask+0x5ca/0x600
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359422]  [<ffffffff8109428b>] kmem_getpages+0x5c/0x127
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359439]  [<ffffffff81094475>] fallback_alloc+0x11f/0x195
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359455]  [<ffffffff81094614>] ____cache_alloc_node+0x129/0x138
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359473]  [<ffffffff81094fdd>] kmem_cache_alloc+0xd1/0xfe
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359492]  [<ffffffff8133c2f9>] sk_prot_alloc+0x2c/0xcd
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359508]  [<ffffffff8133c427>] sk_clone+0x1b/0x24b
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359525]  [<ffffffff81369ce2>] inet_csk_clone+0x13/0x81
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359545]  [<ffffffff8137d698>] tcp_create_openreq_child+0x1d/0x39c
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359564]  [<ffffffff8137c309>] tcp_v4_syn_recv_sock+0x57/0x1bc
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359581]  [<ffffffff8137d50f>] tcp_check_req+0x210/0x37c
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359600]  [<ffffffffa0154423>] ? ipv4_confirm+0x161/0x179 [nf_conntrack_ipv4]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359620]  [<ffffffff8137ba63>] tcp_v4_do_rcv+0xc1/0x1d7
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359637]  [<ffffffff8137c021>] tcp_v4_rcv+0x4a8/0x739
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359654]  [<ffffffff8135ba27>] ? nf_hook_slow+0x63/0xc3
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359671]  [<ffffffff81361bb0>] ? ip_local_deliver_finish+0x0/0x1d0
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359705]  [<ffffffff81361ca8>] ip_local_deliver_finish+0xf8/0x1d0
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359739]  [<ffffffff81361df2>] ip_local_deliver+0x72/0x7a
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359771]  [<ffffffff813618ac>] ip_rcv_finish+0x33c/0x356
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359803]  [<ffffffff81361b79>] ip_rcv+0x2b3/0x2ea
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359836]  [<ffffffff813a2861>] ? packet_rcv_spkt+0x10f/0x11a
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359869]  [<ffffffff8134660a>] netif_receive_skb+0x2cb/0x2ed
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359902]  [<ffffffff81346767>] napi_skb_finish+0x28/0x40
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359934]  [<ffffffff81346ba5>] napi_gro_receive+0x2a/0x2f
Feb 10 11:59:49 beosrv1-t kernel: [1968909.359974]  [<ffffffffa001669d>] igb_poll+0x507/0x86a [igb]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360008]  [<ffffffffa0015ef8>] ? igb_clean_tx_irq+0x1dd/0x47b [igb]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360043]  [<ffffffff81346cb6>] net_rx_action+0xa7/0x178
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360076]  [<ffffffff8103bd21>] __do_softirq+0x96/0x119
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360109]  [<ffffffff8100bf5c>] call_softirq+0x1c/0x28
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360141]  [<ffffffff8100d9e7>] do_softirq+0x33/0x6b
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360172]  [<ffffffff8103b844>] irq_exit+0x36/0x38
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360202]  [<ffffffff8100d0e9>] do_IRQ+0xa3/0xba
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360233]  [<ffffffff8100b7d3>] ret_from_intr+0x0/0xa
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360263]  <EOI>  [<ffffffffa00f046f>] ? xfs_reclaim_inode_shrink+0xc3/0x112 [xfs]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360360]  [<ffffffffa00f0451>] ? xfs_reclaim_inode_shrink+0xa5/0x112 [xfs]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360421]  [<ffffffffa00f04bd>] ? xfs_reclaim_inode_shrink+0x111/0x112 [xfs]
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360473]  [<ffffffff810770fc>] ? shrink_slab+0xd2/0x154
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360505]  [<ffffffff81077e00>] ? try_to_free_pages+0x221/0x31c
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360538]  [<ffffffff81074f4a>] ? isolate_pages_global+0x0/0x1f0
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360572]  [<ffffffff81071d79>] ? __alloc_pages_nodemask+0x3fd/0x600
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360607]  [<ffffffff8109428b>] ? kmem_getpages+0x5c/0x127
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360639]  [<ffffffff81094475>] ? fallback_alloc+0x11f/0x195
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360671]  [<ffffffff81094614>] ? ____cache_alloc_node+0x129/0x138
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360706]  [<ffffffff810a9055>] ? pollwake+0x0/0x5b
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360737]  [<ffffffff810946bf>] ? kmem_cache_alloc_node+0x9c/0xc7
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360770]  [<ffffffff8109472d>] ? __kmalloc_node+0x43/0x45
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360803]  [<ffffffff81340625>] ? __alloc_skb+0x6b/0x164
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360834]  [<ffffffff8133bcc1>] ? sock_alloc_send_pskb+0xdd/0x31c
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360868]  [<ffffffff8133bf10>] ? sock_alloc_send_skb+0x10/0x12
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360901]  [<ffffffff8139e4c2>] ? unix_stream_sendmsg+0x180/0x312
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360936]  [<ffffffff81338270>] ? sock_aio_write+0x109/0x122
Feb 10 11:59:49 beosrv1-t kernel: [1968909.360969]  [<ffffffff8100b7ce>] ? common_interrupt+0xe/0x13
Feb 10 11:59:49 beosrv1-t kernel: [1968909.361002]  [<ffffffff8109a41a>] ? do_sync_write+0xe7/0x12d
Feb 10 11:59:49 beosrv1-t kernel: [1968909.361036]  [<ffffffff81049208>] ? autoremove_wake_function+0x0/0x38
Feb 10 11:59:49 beosrv1-t kernel: [1968909.361070]  [<ffffffff8100b7ce>] ? common_intreclaimable:78357
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211168]  mapped:11679 shmem:26799 pagetables:13497 bounce:0
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211322] Node 0 DMA free:15572kB min:632kB low:788kB high:948kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:14960kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211505] lowmem_reserve[]: 0 2991 24201 24201
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211545] Node 0 DMA32 free:219668kB min:129476kB low:161844kB high:194212kB active_anon:14216kB inactive_anon:115952kB active_file:74252kB inactive_file:1170312kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3063520kB mlocked:0kB dirty:0kB writeback:0kB mapped:676kB shmem:20kB slab_reclaimable:1026120kB slab_unreclaimable:73808kB kernel_stack:1160kB pagetables:1660kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211739] lowmem_reserve[]: 0 0 21210 21210
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211777] Node 0 Normal free:965164kB min:917952kB low:1147440kB high:1376928kB active_anon:2742680kB inactive_anon:293184kB active_file:4801512kB inactive_file:11129708kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:21719040kB mlocked:0kB dirty:600kB writeback:0kB mapped:26356kB shmem:4896kB slab_reclaimable:1780208kB slab_unreclaimable:199576kB kernel_stack:1576kB pagetables:22956kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Feb 10 11:59:49 beosrv1-t kernel: [1968911.211990] lowmem_reserve[]: 0 0 0 0
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212027] Node 1 Normal free:1104084kB min:1049088kB low:1311360kB high:1573632kB active_anon:1736816kB inactive_anon:232580kB active_file:4800152kB inactive_file:16498268kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:24821760kB mlocked:0kB dirty:840kB writeback:0kB mapped:19684kB shmem:102280kB slab_reclaimable:295228kB slab_unreclaimable:40044kB kernel_stack:2880kB pagetables:29372kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212239] lowmem_reserve[]: 0 0 0 0
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212276] Node 0 DMA: 1*4kB 2*8kB 2*16kB 1*32kB 2*64kB 0*128kB 0*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15572kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212363] Node 0 DMA32: 52481*4kB 280*8kB 115*16kB 41*32kB 10*64kB 5*128kB 2*256kB 1*512kB 0*1024kB 1*2048kB 0*4096kB = 219668kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212452] Node 0 Normal: 230307*4kB 4373*8kB 81*16kB 3*32kB 4*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 1*4096kB = 965412kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212541] Node 1 Normal: 262151*4kB 5886*8kB 46*16kB 5*32kB 3*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 1*4096kB = 1104332kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212630] 9651977 total pagecache pages
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212658] 6684 pages in swap cache
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212685] Swap cache stats: add 198950, delete 192266, find 172190568/172202914
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212735] Free swap  = 41892212kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.212761] Total swap = 41943032kB
Feb 10 11:59:49 beosrv1-t kernel: [1968911.509010] 12582896 pages RAM
Feb 10 11:59:49 beosrv1-t kernel: [1968911.509038] 193198 pages reserved
Feb 10 11:59:49 beosrv1-t kernel: [1968911.509063] 727898 pages shared
Feb 10 11:59:49 beosrv1-t kernel: [1968911.509089] 11272895 pages non-shared

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-15  7:44   ` Peter Kruse
@ 2011-02-15 17:30     ` Christoph Lameter
  2011-02-16 12:22       ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-02-15 17:30 UTC (permalink / raw)
  To: Peter Kruse; +Cc: linux-kernel

On Tue, 15 Feb 2011, Peter Kruse wrote:

> > > we have set vm.min_free_kbytes = 2097152 but the problem
> > > obviously did not go away.
> >
> > 2GB of reserves? How much memory does your system have?
>
> 48GB

Ok then you just may potentially clog up the DMA zones. Maybe set the
reserves to a reasonable level like 10M or so?

How many buffers are configured at the various levels for the device that
is receiving messages? I guess that may be a bit on the high side?

> > Could you post the entire messages from the kernel log? We need the OOM
> > info to figure out more about the problem.
> >
>
> I attach one of the call traces, or would it be better if I send the
> kern.log (about 6MB)?

The call traces are sufficient but the traces vanished when I hit reply.
Include them inline next time. It would be good to have the log starting
at the last system boot. There is some information cut off that I would to
see.

An atomic order 1 allocation failed and led to the OOM but it seems that
there is still ample memory available. Slab is in "fallback_alloc" so
something went wrong with the regular allocation attempt. Any use of
cpusets or cgroups?

A significant amount of memory has been allocated to reclaimable slabs.
I guess these are the socket buffers?

Feb 10 11:59:49 beosrv1-t kernel: [1968911.211777] Node 0 Normal
free:965164kB min:917952kB low:1147440kB high:1376928kB
active_anon:2742680kB inactive_anon:293184kB active_file:4801512kB
inactive_file:11129708kB unevictable:0kB isolated(anon):0kB
isolated(file):0kB present:21719040kB mlocked:0kB dirty:600kB
writeback:0kB mapped:26356kB shmem:4896kB slab_reclaimable:1780208kB <-----!!
slab_unreclaimable:199576kB kernel_stack:1576kB pagetables:22956kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no

Could you try to reduce the number of network buffers?


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-15 17:30     ` Christoph Lameter
@ 2011-02-16 12:22       ` Peter Kruse
  2011-02-16 15:59         ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-16 12:22 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: linux-kernel

[-- Attachment #1: Type: text/plain, Size: 2296 bytes --]

Hi Christoph,

thanks again for your time.

Christoph Lameter wrote:
> On Tue, 15 Feb 2011, Peter Kruse wrote:
> 
>> > > we have set vm.min_free_kbytes = 2097152 but the problem
>> > > obviously did not go away.
>> >
>> > 2GB of reserves? How much memory does your system have?
>>
>> 48GB
> 
> Ok then you just may potentially clog up the DMA zones. Maybe set the
> reserves to a reasonable level like 10M or so?

ok, that's what we had before the first incident, and then increased
it to this value to see if it makes difference.

> 
> How many buffers are configured at the various levels for the device that
> is receiving messages? I guess that may be a bit on the high side?

hm, I'm not sure if I know what you want mean or want me to do.

> 
>> > Could you post the entire messages from the kernel log? We need the OOM
>> > info to figure out more about the problem.
>> >
>>
>> I attach one of the call traces, or would it be better if I send the
>> kern.log (about 6MB)?
> 
> The call traces are sufficient but the traces vanished when I hit reply.
> Include them inline next time. It would be good to have the log starting
> at the last system boot. There is some information cut off that I would to
> see.

Ok, I attach the gzipped kern.log.

> 
> An atomic order 1 allocation failed and led to the OOM but it seems that
> there is still ample memory available. Slab is in "fallback_alloc" so
> something went wrong with the regular allocation attempt. Any use of
> cpusets or cgroups?

not that I know of, no.

> 
> A significant amount of memory has been allocated to reclaimable slabs.
> I guess these are the socket buffers?
> 
> Feb 10 11:59:49 beosrv1-t kernel: [1968911.211777] Node 0 Normal
> free:965164kB min:917952kB low:1147440kB high:1376928kB
> active_anon:2742680kB inactive_anon:293184kB active_file:4801512kB
> inactive_file:11129708kB unevictable:0kB isolated(anon):0kB
> isolated(file):0kB present:21719040kB mlocked:0kB dirty:600kB
> writeback:0kB mapped:26356kB shmem:4896kB slab_reclaimable:1780208kB 
> <-----!!
> slab_unreclaimable:199576kB kernel_stack:1576kB pagetables:22956kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> 
> Could you try to reduce the number of network buffers?

which parameter?

thanks,

   Peter


[-- Attachment #2: kern.log.gz --]
[-- Type: application/x-gzip, Size: 330458 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-16 12:22       ` Peter Kruse
@ 2011-02-16 15:59         ` Christoph Lameter
  2011-02-16 16:03           ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-02-16 15:59 UTC (permalink / raw)
  To: eric.dumazet; +Cc: Peter Kruse, linux-kernel

On Wed, 16 Feb 2011, Peter Kruse wrote:

> > How many buffers are configured at the various levels for the device that
> > is receiving messages? I guess that may be a bit on the high side?
>
> hm, I'm not sure if I know what you want mean or want me to do.

NICs typically can be configured via ethtool for various queue sizes. Also
ifconfig can do some queue config. The ip tool too etc. Maybe Eric can
have a look at this. Looks like its an sk_clone from an interrupt context
that is causing the trouble.

> > The call traces are sufficient but the traces vanished when I hit reply.
> > Include them inline next time. It would be good to have the log starting
> > at the last system boot. There is some information cut off that I would to
> > see.
>
> Ok, I attach the gzipped kern.log.

We still do not have the messages from bootup. I can only see the OOM
messages itself not how the kernel booted up.

> > A significant amount of memory has been allocated to reclaimable slabs.
> > I guess these are the socket buffers?
> >
> > Feb 10 11:59:49 beosrv1-t kernel: [1968911.211777] Node 0 Normal
> > free:965164kB min:917952kB low:1147440kB high:1376928kB
> > active_anon:2742680kB inactive_anon:293184kB active_file:4801512kB
> > inactive_file:11129708kB unevictable:0kB isolated(anon):0kB
> > isolated(file):0kB present:21719040kB mlocked:0kB dirty:600kB
> > writeback:0kB mapped:26356kB shmem:4896kB slab_reclaimable:1780208kB
> > <-----!!
> > slab_unreclaimable:199576kB kernel_stack:1576kB pagetables:22956kB
> > unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> > all_unreclaimable? no
> >
> > Could you try to reduce the number of network buffers?
>
> which parameter?

Ethtool, ifconfig and then there are various parameters in
/proc/sys/net/ipv4.

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-16 15:59         ` Christoph Lameter
@ 2011-02-16 16:03           ` Peter Kruse
  2011-02-16 16:14             ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-16 16:03 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 308 bytes --]

Hi Christoph,

Christoph Lameter wrote:
> 
> We still do not have the messages from bootup. I can only see the OOM
> messages itself not how the kernel booted up.

I see, the boot messages of the boot after those failures is included,
I thought that would be ok.. anyways, included the boot messages.

Peter

[-- Attachment #2: kern.log.2.gz --]
[-- Type: application/x-gzip, Size: 12737 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-16 16:03           ` Peter Kruse
@ 2011-02-16 16:14             ` Christoph Lameter
  2011-02-17  7:31               ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-02-16 16:14 UTC (permalink / raw)
  To: Peter Kruse; +Cc: eric.dumazet, linux-kernel

[-- Attachment #1: Type: TEXT/PLAIN, Size: 583 bytes --]

On Wed, 16 Feb 2011, Peter Kruse wrote:

> > messages itself not how the kernel booted up.
>
> I see, the boot messages of the boot after those failures is included,
> I thought that would be ok.. anyways, included the boot messages.

Oww. A large number of additional higher order allocations from iptables.
Order 6. But still only partial boot message. I need to see the memory
layout discovered by the kernel and for that I need the early boot messages.

Also since this is 2.6.32: Could you upgrade to the latest which is
2.6.32.28? There may be a fix in there for your problem.

[-- Attachment #2: Type: APPLICATION/X-GZIP, Size: 12737 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-16 16:14             ` Christoph Lameter
@ 2011-02-17  7:31               ` Peter Kruse
  2011-02-17 17:03                 ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-17  7:31 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 551 bytes --]

Hi Christoph,

Christoph Lameter wrote:
> Oww. A large number of additional higher order allocations from iptables.
> Order 6. But still only partial boot message. I need to see the memory
> layout discovered by the kernel and for that I need the early boot 
> messages.

ok, I attach the early dmesg I hope this contains the information
you need.

> Also since this is 2.6.32: Could you upgrade to the latest which is
> 2.6.32.28? There may be a fix in there for your problem.

we can try, which problem/patch do you have in mind?

Thanks,

   Peter

[-- Attachment #2: dmesg.gz --]
[-- Type: application/x-gzip, Size: 7546 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-17  7:31               ` Peter Kruse
@ 2011-02-17 17:03                 ` Christoph Lameter
  2011-02-18 12:30                   ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-02-17 17:03 UTC (permalink / raw)
  To: Peter Kruse; +Cc: eric.dumazet, linux-kernel

On Thu, 17 Feb 2011, Peter Kruse wrote:

> Christoph Lameter wrote:
> > Oww. A large number of additional higher order allocations from iptables.
> > Order 6. But still only partial boot message. I need to see the memory
> > layout discovered by the kernel and for that I need the early boot messages.
>
> ok, I attach the early dmesg I hope this contains the information
> you need.

No it only contains what you sent before. I need the early boot
messages.


y

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-17 17:03                 ` Christoph Lameter
@ 2011-02-18 12:30                   ` Peter Kruse
  2011-02-24 12:01                     ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-18 12:30 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: Peter Kruse, eric.dumazet, linux-kernel

Hi,

> On Thu, 17 Feb 2011, Peter Kruse wrote:
>
>> ok, I attach the early dmesg I hope this contains the information
>> you need.
>
> No it only contains what you sent before. I need the early boot
> messages.

I see, will have access to that machine again on Monday,
will try to get them then.

thanks for your patience,

 Peter


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-18 12:30                   ` Peter Kruse
@ 2011-02-24 12:01                     ` Peter Kruse
  2011-04-12 15:01                       ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-02-24 12:01 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 814 bytes --]

Hello,

Peter Kruse wrote:
>> On Thu, 17 Feb 2011, Peter Kruse wrote:
>>
>>> ok, I attach the early dmesg I hope this contains the information
>>> you need.
>> No it only contains what you sent before. I need the early boot
>> messages.
> 
> I see, will have access to that machine again on Monday,
> will try to get them then.

it took a while to find a date for a reboot...  Unfortunately
it was not possible to get the early boot messages with the
kernel 2.6.32.23 since the compiled in log buffer is too
small.  So we installed as you suggested a more recent kernel
2.6.32.29 with a bigger log buffer, I attach the dmesg
of that, and hope that the information in there is useful.
We will keep an eye on that server with the newer kernel
to see if the allocation failures appear again.

Best regards,

   Peter

[-- Attachment #2: dmesg-2.6.32.29.gz --]
[-- Type: application/x-gzip, Size: 13689 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-02-24 12:01                     ` Peter Kruse
@ 2011-04-12 15:01                       ` Peter Kruse
  2011-04-12 18:08                         ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-04-12 15:01 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 937 bytes --]

Hello,

On 02/24/2011 01:01 PM, Peter Kruse wrote:
> it took a while to find a date for a reboot... Unfortunately
> it was not possible to get the early boot messages with the
> kernel 2.6.32.23 since the compiled in log buffer is too
> small. So we installed as you suggested a more recent kernel
> 2.6.32.29 with a bigger log buffer, I attach the dmesg
> of that, and hope that the information in there is useful.
> We will keep an eye on that server with the newer kernel
> to see if the allocation failures appear again.

the server was running for a few without any more allocation
failures with kernel 2.6.32.29 but at one point the server
stopped responding, it was still possible for a while to
get a login, and trying to kill some processes but that
didn't succeed.  But after that even login was
no longer possible so we had to reset it.
I attach the call trace, I hope you can find out what is
the problem.

thanks,

   Peter

[-- Attachment #2: kern.log.gz --]
[-- Type: application/x-gzip, Size: 125407 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-04-12 15:01                       ` Peter Kruse
@ 2011-04-12 18:08                         ` Christoph Lameter
  2011-04-13  1:34                           ` David Rientjes
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-04-12 18:08 UTC (permalink / raw)
  To: Peter Kruse; +Cc: eric.dumazet, linux-kernel

On Tue, 12 Apr 2011, Peter Kruse wrote:

> Hello,
>
> On 02/24/2011 01:01 PM, Peter Kruse wrote:
> > it took a while to find a date for a reboot... Unfortunately
> > it was not possible to get the early boot messages with the
> > kernel 2.6.32.23 since the compiled in log buffer is too
> > small. So we installed as you suggested a more recent kernel
> > 2.6.32.29 with a bigger log buffer, I attach the dmesg
> > of that, and hope that the information in there is useful.
> > We will keep an eye on that server with the newer kernel
> > to see if the allocation failures appear again.
>
> the server was running for a few without any more allocation
> failures with kernel 2.6.32.29 but at one point the server
> stopped responding, it was still possible for a while to
> get a login, and trying to kill some processes but that
> didn't succeed.  But after that even login was
> no longer possible so we had to reset it.
> I attach the call trace, I hope you can find out what is
> the problem.

The problem maybe that you have lots and lots of SCSI devices which
consume ZONE_DMA memory for their control structures. I guess that is
oversubscribing the 16M zone.


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-04-12 18:08                         ` Christoph Lameter
@ 2011-04-13  1:34                           ` David Rientjes
  2011-04-13  7:13                             ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: David Rientjes @ 2011-04-13  1:34 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: Peter Kruse, eric.dumazet, linux-kernel

On Tue, 12 Apr 2011, Christoph Lameter wrote:

> > > it took a while to find a date for a reboot... Unfortunately
> > > it was not possible to get the early boot messages with the
> > > kernel 2.6.32.23 since the compiled in log buffer is too
> > > small. So we installed as you suggested a more recent kernel
> > > 2.6.32.29 with a bigger log buffer, I attach the dmesg
> > > of that, and hope that the information in there is useful.
> > > We will keep an eye on that server with the newer kernel
> > > to see if the allocation failures appear again.
> > 
> > the server was running for a few without any more allocation
> > failures with kernel 2.6.32.29 but at one point the server
> > stopped responding, it was still possible for a while to
> > get a login, and trying to kill some processes but that
> > didn't succeed.  But after that even login was
> > no longer possible so we had to reset it.
> > I attach the call trace, I hope you can find out what is
> > the problem.
> 
> The problem maybe that you have lots and lots of SCSI devices which
> consume ZONE_DMA memory for their control structures. I guess that is
> oversubscribing the 16M zone.
> 

You can try to get more memory reserves specifically for lowmem in 
ZONE_DMA by changing /proc/sys/vm/lowmem_reserve_ratio.  The values are 
ratios, so lowering the numbers will yield larger amounts of memory 
reserves in ZONE_DMA for GFP_DMA allocations.  Try lowering the non-zero 
entries to 1 to reserve the entire zone for lowmem, assuming your system 
has enough RAM for everything else you're running.

This will verify if ZONE_DMA is being depleted from the larger number of 
SCSI devices.  If you don't get any additional page allocation failures, 
then check how much memory in ZONE_DMA is used at peak and that would be a 
sane reserve ratio to use next time you restart the system.

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-04-13  1:34                           ` David Rientjes
@ 2011-04-13  7:13                             ` Peter Kruse
  2011-04-13 16:17                               ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-04-13  7:13 UTC (permalink / raw)
  To: David Rientjes; +Cc: Christoph Lameter, eric.dumazet, linux-kernel

Hello,

thanks for your replies, I appreciate that.

On 04/13/2011 03:34 AM, David Rientjes wrote:
> On Tue, 12 Apr 2011, Christoph Lameter wrote:
>
>> The problem maybe that you have lots and lots of SCSI devices which
>> consume ZONE_DMA memory for their control structures. I guess that is
>> oversubscribing the 16M zone.

but there are only two devices:

# fdisk -l

Disk /dev/sda: 249.8 GB, 249865175040 bytes
255 heads, 63 sectors/track, 30377 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x4ac39024

    Device Boot      Start         End      Blocks   Id  System
/dev/sda1               1          13      104422   83  Linux
/dev/sda2              14       30377   243898830   8e  Linux LVM

WARNING: GPT (GUID Partition Table) detected on '/dev/sdb'! The util fdisk 
doesn't support GPT. Use GNU Parted.


Disk /dev/sdb: 37946.0 GB, 37946025574400 bytes
255 heads, 63 sectors/track, 4613341 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x00000000

Disk /dev/sdb doesn't contain a valid partition table

> You can try to get more memory reserves specifically for lowmem in
> ZONE_DMA by changing /proc/sys/vm/lowmem_reserve_ratio.  The values are
> ratios, so lowering the numbers will yield larger amounts of memory
> reserves in ZONE_DMA for GFP_DMA allocations.  Try lowering the non-zero
> entries to 1 to reserve the entire zone for lowmem, assuming your system
> has enough RAM for everything else you're running.

this server has 48GB - that should be enough.

> This will verify if ZONE_DMA is being depleted from the larger number of
> SCSI devices.  If you don't get any additional page allocation failures,
> then check how much memory in ZONE_DMA is used at peak and that would be a
> sane reserve ratio to use next time you restart the system.

Could that still be a problem if there are only two scsi devices?

Regards,

   Peter

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-04-13  7:13                             ` Peter Kruse
@ 2011-04-13 16:17                               ` Christoph Lameter
  2011-05-19 11:56                                 ` Peter Kruse
       [not found]                                 ` <4E09BEA1.1080501@q-leap.de>
  0 siblings, 2 replies; 27+ messages in thread
From: Christoph Lameter @ 2011-04-13 16:17 UTC (permalink / raw)
  To: Peter Kruse; +Cc: David Rientjes, eric.dumazet, linux-kernel

On Wed, 13 Apr 2011, Peter Kruse wrote:

> Hello,
>
> thanks for your replies, I appreciate that.
>
> On 04/13/2011 03:34 AM, David Rientjes wrote:
> > On Tue, 12 Apr 2011, Christoph Lameter wrote:
> >
> > > The problem maybe that you have lots and lots of SCSI devices which
> > > consume ZONE_DMA memory for their control structures. I guess that is
> > > oversubscribing the 16M zone.
>
> but there are only two devices:

The output you sent me showed a long list of devices. Maybe there is a
broken driver /device that continues being probed?

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-04-13 16:17                               ` Christoph Lameter
@ 2011-05-19 11:56                                 ` Peter Kruse
  2011-05-19 16:00                                   ` Christoph Lameter
       [not found]                                 ` <4E09BEA1.1080501@q-leap.de>
  1 sibling, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-05-19 11:56 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: David Rientjes, eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 1486 bytes --]

Hello again,

you may remember, we have a server running 2.6.32.29
and once in a while it just crashes, meaning that
it just stops responding, and we have to reset it.
The kernel itself and some processes are still running,
and it is possible to initiate the sysRQ.
The mentioned allocation failures are gone after the update
to the kernel version, but the server crashed again
after 40 days running without any problem.

At this time kswapd0/1 started to consume 99% CPU time
and until the server was reset 8 hours later
never used less than 50% CPU time.  Shortly after
that (half an hour) the disk reads dropped down to zero.  And
a program produced the attached Call Trace.  I also
attach the process information of kswapd (provided by collectl).

Thanks,

  Peter

On 04/13/2011 06:17 PM, Christoph Lameter wrote:
> On Wed, 13 Apr 2011, Peter Kruse wrote:
> 
>> Hello,
>>
>> thanks for your replies, I appreciate that.
>>
>> On 04/13/2011 03:34 AM, David Rientjes wrote:
>>> On Tue, 12 Apr 2011, Christoph Lameter wrote:
>>>
>>>> The problem maybe that you have lots and lots of SCSI devices which
>>>> consume ZONE_DMA memory for their control structures. I guess that is
>>>> oversubscribing the 16M zone.
>>
>> but there are only two devices:
> 
> The output you sent me showed a long list of devices. Maybe there is a
> broken driver /device that continues being probed?
> 


-- 
Peter Kruse <pk@q-leap.de>
Q-Leap Networks GmbH
phone: +497034-2776-175, mobile: +491522-1593877

[-- Attachment #2: messages --]
[-- Type: text/plain, Size: 19490 bytes --]

May 16 02:24:36 beosrv1-t kernel: [3504667.830773] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:24:36 beosrv1-t kernel: [3504667.830797]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:24:36 beosrv1-t kernel: [3504667.830826]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:24:36 beosrv1-t kernel: [3504667.830854]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:24:36 beosrv1-t kernel: [3504667.830882] Call Trace:
May 16 02:24:36 beosrv1-t kernel: [3504667.830899]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:24:36 beosrv1-t kernel: [3504667.830918]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:24:36 beosrv1-t kernel: [3504667.830939]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:24:36 beosrv1-t kernel: [3504667.830957]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:24:36 beosrv1-t kernel: [3504667.830975]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:24:36 beosrv1-t kernel: [3504667.830991]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:24:36 beosrv1-t kernel: [3504667.831011]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:24:36 beosrv1-t kernel: [3504667.831027]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:24:36 beosrv1-t kernel: [3504667.831045]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:24:36 beosrv1-t kernel: [3504667.831076]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:24:36 beosrv1-t kernel: [3504667.831111]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:24:36 beosrv1-t kernel: [3504667.831146]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:24:36 beosrv1-t kernel: [3504667.831177]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:24:36 beosrv1-t kernel: [3504667.831209]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:26:35 beosrv1-t kernel: [3504787.810748] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:26:35 beosrv1-t kernel: [3504787.810773]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:26:35 beosrv1-t kernel: [3504787.810802]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:26:35 beosrv1-t kernel: [3504787.810829]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:26:35 beosrv1-t kernel: [3504787.810857] Call Trace:
May 16 02:26:35 beosrv1-t kernel: [3504787.810875]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:26:35 beosrv1-t kernel: [3504787.810893]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:26:35 beosrv1-t kernel: [3504787.810914]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:26:35 beosrv1-t kernel: [3504787.810932]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:26:35 beosrv1-t kernel: [3504787.810950]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:26:35 beosrv1-t kernel: [3504787.810966]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:26:35 beosrv1-t kernel: [3504787.810985]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:26:35 beosrv1-t kernel: [3504787.811002]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:26:35 beosrv1-t kernel: [3504787.811020]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:26:35 beosrv1-t kernel: [3504787.811051]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:26:35 beosrv1-t kernel: [3504787.811086]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:26:35 beosrv1-t kernel: [3504787.811121]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:26:35 beosrv1-t kernel: [3504787.811152]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:26:35 beosrv1-t kernel: [3504787.811184]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:28:35 beosrv1-t kernel: [3504907.579079] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:28:35 beosrv1-t kernel: [3504907.579103]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:28:35 beosrv1-t kernel: [3504907.579132]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:28:35 beosrv1-t kernel: [3504907.579160]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:28:35 beosrv1-t kernel: [3504907.579188] Call Trace:
May 16 02:28:35 beosrv1-t kernel: [3504907.579205]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:28:35 beosrv1-t kernel: [3504907.579224]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:28:35 beosrv1-t kernel: [3504907.579244]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:28:35 beosrv1-t kernel: [3504907.579262]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:28:35 beosrv1-t kernel: [3504907.579280]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:28:35 beosrv1-t kernel: [3504907.579296]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:28:35 beosrv1-t kernel: [3504907.579316]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:28:35 beosrv1-t kernel: [3504907.579333]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:28:35 beosrv1-t kernel: [3504907.579351]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:28:35 beosrv1-t kernel: [3504907.579383]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:28:35 beosrv1-t kernel: [3504907.579418]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:28:35 beosrv1-t kernel: [3504907.579453]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:28:35 beosrv1-t kernel: [3504907.579484]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:28:35 beosrv1-t kernel: [3504907.579516]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:30:35 beosrv1-t kernel: [3505027.351433] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:30:35 beosrv1-t kernel: [3505027.351458]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:30:35 beosrv1-t kernel: [3505027.351487]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:30:35 beosrv1-t kernel: [3505027.351515]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:30:35 beosrv1-t kernel: [3505027.351543] Call Trace:
May 16 02:30:35 beosrv1-t kernel: [3505027.351560]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:30:35 beosrv1-t kernel: [3505027.351578]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:30:35 beosrv1-t kernel: [3505027.351599]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:30:35 beosrv1-t kernel: [3505027.351617]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:30:35 beosrv1-t kernel: [3505027.351635]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:30:35 beosrv1-t kernel: [3505027.351652]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:30:35 beosrv1-t kernel: [3505027.351671]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:30:35 beosrv1-t kernel: [3505027.351688]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:30:35 beosrv1-t kernel: [3505027.351705]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:30:35 beosrv1-t kernel: [3505027.351737]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:30:35 beosrv1-t kernel: [3505027.351771]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:30:35 beosrv1-t kernel: [3505027.351806]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:30:35 beosrv1-t kernel: [3505027.351838]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:30:35 beosrv1-t kernel: [3505027.351869]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:32:35 beosrv1-t kernel: [3505147.119797] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:32:35 beosrv1-t kernel: [3505147.119822]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:32:35 beosrv1-t kernel: [3505147.119851]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:32:35 beosrv1-t kernel: [3505147.119879]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:32:35 beosrv1-t kernel: [3505147.119907] Call Trace:
May 16 02:32:35 beosrv1-t kernel: [3505147.119924]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:32:35 beosrv1-t kernel: [3505147.119942]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:32:35 beosrv1-t kernel: [3505147.119963]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:32:35 beosrv1-t kernel: [3505147.119982]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:32:35 beosrv1-t kernel: [3505147.120000]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:32:35 beosrv1-t kernel: [3505147.120016]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:32:35 beosrv1-t kernel: [3505147.120036]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:32:35 beosrv1-t kernel: [3505147.120053]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:32:35 beosrv1-t kernel: [3505147.120070]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:32:35 beosrv1-t kernel: [3505147.120102]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:32:35 beosrv1-t kernel: [3505147.120137]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:32:35 beosrv1-t kernel: [3505147.120171]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:32:35 beosrv1-t kernel: [3505147.120203]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:32:35 beosrv1-t kernel: [3505147.120234]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:34:35 beosrv1-t kernel: [3505266.888143] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:34:35 beosrv1-t kernel: [3505266.888168]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:34:35 beosrv1-t kernel: [3505266.888197]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:34:35 beosrv1-t kernel: [3505266.888225]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:34:35 beosrv1-t kernel: [3505266.888253] Call Trace:
May 16 02:34:35 beosrv1-t kernel: [3505266.888270]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:34:35 beosrv1-t kernel: [3505266.888288]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:34:35 beosrv1-t kernel: [3505266.888309]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:34:35 beosrv1-t kernel: [3505266.888327]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:34:35 beosrv1-t kernel: [3505266.888345]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:34:35 beosrv1-t kernel: [3505266.888361]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:34:35 beosrv1-t kernel: [3505266.888381]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:34:35 beosrv1-t kernel: [3505266.888398]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:34:35 beosrv1-t kernel: [3505266.888415]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:34:35 beosrv1-t kernel: [3505266.888447]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:34:35 beosrv1-t kernel: [3505266.888482]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:34:35 beosrv1-t kernel: [3505266.888517]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:34:35 beosrv1-t kernel: [3505266.888548]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:34:35 beosrv1-t kernel: [3505266.888579]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:36:35 beosrv1-t kernel: [3505386.656500] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:36:35 beosrv1-t kernel: [3505386.656525]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:36:35 beosrv1-t kernel: [3505386.656553]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:36:35 beosrv1-t kernel: [3505386.656581]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:36:35 beosrv1-t kernel: [3505386.656609] Call Trace:
May 16 02:36:35 beosrv1-t kernel: [3505386.656626]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:36:35 beosrv1-t kernel: [3505386.656644]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:36:35 beosrv1-t kernel: [3505386.656666]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:36:35 beosrv1-t kernel: [3505386.656684]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:36:35 beosrv1-t kernel: [3505386.656701]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:36:35 beosrv1-t kernel: [3505386.656717]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:36:35 beosrv1-t kernel: [3505386.656737]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:36:35 beosrv1-t kernel: [3505386.656754]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:36:35 beosrv1-t kernel: [3505386.656771]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:36:35 beosrv1-t kernel: [3505386.656803]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:36:35 beosrv1-t kernel: [3505386.656838]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:36:35 beosrv1-t kernel: [3505386.656872]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:36:35 beosrv1-t kernel: [3505386.656904]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:36:35 beosrv1-t kernel: [3505386.656935]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:38:35 beosrv1-t kernel: [3505506.424861] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:38:35 beosrv1-t kernel: [3505506.424886]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:38:35 beosrv1-t kernel: [3505506.424915]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:38:35 beosrv1-t kernel: [3505506.424943]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:38:35 beosrv1-t kernel: [3505506.424971] Call Trace:
May 16 02:38:35 beosrv1-t kernel: [3505506.424988]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:38:35 beosrv1-t kernel: [3505506.425006]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:38:35 beosrv1-t kernel: [3505506.425027]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:38:35 beosrv1-t kernel: [3505506.425045]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:38:35 beosrv1-t kernel: [3505506.425063]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:38:35 beosrv1-t kernel: [3505506.425079]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:38:35 beosrv1-t kernel: [3505506.425099]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:38:35 beosrv1-t kernel: [3505506.425116]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:38:35 beosrv1-t kernel: [3505506.425134]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:38:35 beosrv1-t kernel: [3505506.425165]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:38:35 beosrv1-t kernel: [3505506.425200]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:38:35 beosrv1-t kernel: [3505506.425235]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:38:35 beosrv1-t kernel: [3505506.425266]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:38:35 beosrv1-t kernel: [3505506.425298]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:40:35 beosrv1-t kernel: [3505626.404818] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:40:35 beosrv1-t kernel: [3505626.404843]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:40:35 beosrv1-t kernel: [3505626.404872]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:40:35 beosrv1-t kernel: [3505626.404900]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:40:35 beosrv1-t kernel: [3505626.404928] Call Trace:
May 16 02:40:35 beosrv1-t kernel: [3505626.404945]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:40:35 beosrv1-t kernel: [3505626.404963]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:40:35 beosrv1-t kernel: [3505626.404984]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:40:35 beosrv1-t kernel: [3505626.405002]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:40:35 beosrv1-t kernel: [3505626.405020]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:40:35 beosrv1-t kernel: [3505626.405036]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:40:35 beosrv1-t kernel: [3505626.405056]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:40:35 beosrv1-t kernel: [3505626.405073]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:40:35 beosrv1-t kernel: [3505626.405091]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:40:35 beosrv1-t kernel: [3505626.405122]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:40:35 beosrv1-t kernel: [3505626.405157]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:40:35 beosrv1-t kernel: [3505626.405192]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:40:35 beosrv1-t kernel: [3505626.405223]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:40:35 beosrv1-t kernel: [3505626.405255]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b
May 16 02:42:36 beosrv1-t kernel: [3505746.348825] pv            D ffffffffffffffff     0 20917  10814 0x00000000
May 16 02:42:36 beosrv1-t kernel: [3505746.348849]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847
May 16 02:42:36 beosrv1-t kernel: [3505746.348879]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0
May 16 02:42:36 beosrv1-t kernel: [3505746.348907]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0
May 16 02:42:36 beosrv1-t kernel: [3505746.348935] Call Trace:
May 16 02:42:36 beosrv1-t kernel: [3505746.348952]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a
May 16 02:42:36 beosrv1-t kernel: [3505746.348970]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61
May 16 02:42:36 beosrv1-t kernel: [3505746.348991]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133
May 16 02:42:36 beosrv1-t kernel: [3505746.349009]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d
May 16 02:42:36 beosrv1-t kernel: [3505746.349027]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8
May 16 02:42:36 beosrv1-t kernel: [3505746.349044]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254
May 16 02:42:36 beosrv1-t kernel: [3505746.349063]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d
May 16 02:42:36 beosrv1-t kernel: [3505746.349080]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d
May 16 02:42:36 beosrv1-t kernel: [3505746.349098]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4
May 16 02:42:36 beosrv1-t kernel: [3505746.349129]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38
May 16 02:42:36 beosrv1-t kernel: [3505746.349164]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea
May 16 02:42:36 beosrv1-t kernel: [3505746.349199]  [<ffffffff8109ba86>] vfs_read+0xab/0x147
May 16 02:42:36 beosrv1-t kernel: [3505746.349230]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f
May 16 02:42:36 beosrv1-t kernel: [3505746.349261]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

[-- Attachment #3: kswapd.collectl --]
[-- Type: text/plain, Size: 4500 bytes --]

#Time      PID  User     PR  PPID THRD S   VSZ   RSS CP  SysT  UsrT Pct  AccuTime MajF MinF Command
01:46:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0
01:46:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1
01:47:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0
01:47:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1
01:48:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0
01:48:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1
01:49:00    77  root     20     2    0 R     0     0  2 55.48  0.00  92 387:02.99    0    0 kswapd0
01:49:00    78  root     20     2    0 S     0     0  7  0.70  0.00   1 305:02.95    0    0 kswapd1
01:50:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 388:02.87    0    0 kswapd0
01:50:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:51:00    77  root     20     2    0 R     0     0  2 59.86  0.00  99 389:02.73    0    0 kswapd0
01:51:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:52:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 390:02.62    0    0 kswapd0
01:52:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:53:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 391:02.51    0    0 kswapd0
01:53:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:54:00    77  root     20     2    0 R     0     0  2 59.11  0.00  98 392:01.62    0    0 kswapd0
01:54:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:55:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 393:01.50    0    0 kswapd0
01:55:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:56:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 394:01.39    0    0 kswapd0
01:56:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:57:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 395:01.28    0    0 kswapd0
01:57:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1
01:58:00    77  root     20     2    0 R     0     0  2 59.96  0.00  99 396:01.24    0    0 kswapd0
01:58:00    78  root     20     2    0 R     0     0  7 38.42  0.00  64 305:41.37    0    0 kswapd1
01:59:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 397:01.13    0    0 kswapd0
01:59:00    78  root     20     2    0 R     0     0  7 59.84  0.00  99 306:41.21    0    0 kswapd1
02:00:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 398:01.01    0    0 kswapd0
02:00:00    78  root     20     2    0 R     0     0  7 59.88  0.00  99 307:41.09    0    0 kswapd1
02:01:00    77  root     20     2    0 R     0     0  2 59.77  0.00  99 399:00.78    0    0 kswapd0
02:01:00    78  root     20     2    0 R     0     0  7 59.80  0.00  99 308:40.89    0    0 kswapd1
02:02:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 400:00.66    0    0 kswapd0
02:02:00    78  root     20     2    0 R     0     0  7 59.88  0.00  99 309:40.77    0    0 kswapd1
02:03:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 401:00.55    0    0 kswapd0
02:03:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 310:40.66    0    0 kswapd1
02:04:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 402:00.44    0    0 kswapd0
02:04:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 311:40.55    0    0 kswapd1
02:05:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 403:00.33    0    0 kswapd0
02:05:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 312:40.44    0    0 kswapd1
02:06:00    77  root     20     2    0 R     0     0  3 59.87  0.00  99 404:00.20    0    0 kswapd0
02:06:00    78  root     20     2    0 R     0     0  5 59.87  0.00  99 313:40.31    0    0 kswapd1
02:07:00    77  root     20     2    0 R     0     0  3 59.90  0.00  99 405:00.10    0    0 kswapd0
02:07:00    78  root     20     2    0 R     0     0  5 59.90  0.00  99 314:40.21    0    0 kswapd1

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-05-19 11:56                                 ` Peter Kruse
@ 2011-05-19 16:00                                   ` Christoph Lameter
  2011-05-23  6:34                                     ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-05-19 16:00 UTC (permalink / raw)
  To: Peter Kruse; +Cc: David Rientjes, eric.dumazet, linux-kernel

[-- Attachment #1: Type: TEXT/PLAIN, Size: 941 bytes --]

On Thu, 19 May 2011, Peter Kruse wrote:

> you may remember, we have a server running 2.6.32.29
> and once in a while it just crashes, meaning that
> it just stops responding, and we have to reset it.
> The kernel itself and some processes are still running,
> and it is possible to initiate the sysRQ.
> The mentioned allocation failures are gone after the update
> to the kernel version, but the server crashed again
> after 40 days running without any problem.

Good to hear.
>
> At this time kswapd0/1 started to consume 99% CPU time
> and until the server was reset 8 hours later
> never used less than 50% CPU time.  Shortly after
> that (half an hour) the disk reads dropped down to zero.  And
> a program produced the attached Call Trace.  I also
> attach the process information of kswapd (provided by collectl).

We need the complete system log starting from bootup.

This looks like it has something to do with mutexes and pipes.

[-- Attachment #2: Type: TEXT/PLAIN, Size: 19680 bytes --]

May 16 02:24:36 beosrv1-t kernel: [3504667.830773] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:24:36 beosrv1-t kernel: [3504667.830797]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:24:36 beosrv1-t kernel: [3504667.830826]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:24:36 beosrv1-t kernel: [3504667.830854]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:24:36 beosrv1-t kernel: [3504667.830882] Call Trace:

May 16 02:24:36 beosrv1-t kernel: [3504667.830899]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:24:36 beosrv1-t kernel: [3504667.830918]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:24:36 beosrv1-t kernel: [3504667.830939]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:24:36 beosrv1-t kernel: [3504667.830957]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:24:36 beosrv1-t kernel: [3504667.830975]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:24:36 beosrv1-t kernel: [3504667.830991]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:24:36 beosrv1-t kernel: [3504667.831011]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:24:36 beosrv1-t kernel: [3504667.831027]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:24:36 beosrv1-t kernel: [3504667.831045]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:24:36 beosrv1-t kernel: [3504667.831076]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:24:36 beosrv1-t kernel: [3504667.831111]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:24:36 beosrv1-t kernel: [3504667.831146]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:24:36 beosrv1-t kernel: [3504667.831177]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:24:36 beosrv1-t kernel: [3504667.831209]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:26:35 beosrv1-t kernel: [3504787.810748] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:26:35 beosrv1-t kernel: [3504787.810773]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:26:35 beosrv1-t kernel: [3504787.810802]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:26:35 beosrv1-t kernel: [3504787.810829]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:26:35 beosrv1-t kernel: [3504787.810857] Call Trace:

May 16 02:26:35 beosrv1-t kernel: [3504787.810875]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:26:35 beosrv1-t kernel: [3504787.810893]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:26:35 beosrv1-t kernel: [3504787.810914]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:26:35 beosrv1-t kernel: [3504787.810932]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:26:35 beosrv1-t kernel: [3504787.810950]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:26:35 beosrv1-t kernel: [3504787.810966]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:26:35 beosrv1-t kernel: [3504787.810985]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:26:35 beosrv1-t kernel: [3504787.811002]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:26:35 beosrv1-t kernel: [3504787.811020]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:26:35 beosrv1-t kernel: [3504787.811051]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:26:35 beosrv1-t kernel: [3504787.811086]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:26:35 beosrv1-t kernel: [3504787.811121]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:26:35 beosrv1-t kernel: [3504787.811152]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:26:35 beosrv1-t kernel: [3504787.811184]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:28:35 beosrv1-t kernel: [3504907.579079] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:28:35 beosrv1-t kernel: [3504907.579103]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:28:35 beosrv1-t kernel: [3504907.579132]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:28:35 beosrv1-t kernel: [3504907.579160]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:28:35 beosrv1-t kernel: [3504907.579188] Call Trace:

May 16 02:28:35 beosrv1-t kernel: [3504907.579205]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:28:35 beosrv1-t kernel: [3504907.579224]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:28:35 beosrv1-t kernel: [3504907.579244]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:28:35 beosrv1-t kernel: [3504907.579262]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:28:35 beosrv1-t kernel: [3504907.579280]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:28:35 beosrv1-t kernel: [3504907.579296]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:28:35 beosrv1-t kernel: [3504907.579316]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:28:35 beosrv1-t kernel: [3504907.579333]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:28:35 beosrv1-t kernel: [3504907.579351]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:28:35 beosrv1-t kernel: [3504907.579383]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:28:35 beosrv1-t kernel: [3504907.579418]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:28:35 beosrv1-t kernel: [3504907.579453]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:28:35 beosrv1-t kernel: [3504907.579484]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:28:35 beosrv1-t kernel: [3504907.579516]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:30:35 beosrv1-t kernel: [3505027.351433] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:30:35 beosrv1-t kernel: [3505027.351458]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:30:35 beosrv1-t kernel: [3505027.351487]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:30:35 beosrv1-t kernel: [3505027.351515]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:30:35 beosrv1-t kernel: [3505027.351543] Call Trace:

May 16 02:30:35 beosrv1-t kernel: [3505027.351560]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:30:35 beosrv1-t kernel: [3505027.351578]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:30:35 beosrv1-t kernel: [3505027.351599]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:30:35 beosrv1-t kernel: [3505027.351617]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:30:35 beosrv1-t kernel: [3505027.351635]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:30:35 beosrv1-t kernel: [3505027.351652]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:30:35 beosrv1-t kernel: [3505027.351671]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:30:35 beosrv1-t kernel: [3505027.351688]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:30:35 beosrv1-t kernel: [3505027.351705]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:30:35 beosrv1-t kernel: [3505027.351737]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:30:35 beosrv1-t kernel: [3505027.351771]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:30:35 beosrv1-t kernel: [3505027.351806]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:30:35 beosrv1-t kernel: [3505027.351838]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:30:35 beosrv1-t kernel: [3505027.351869]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:32:35 beosrv1-t kernel: [3505147.119797] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:32:35 beosrv1-t kernel: [3505147.119822]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:32:35 beosrv1-t kernel: [3505147.119851]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:32:35 beosrv1-t kernel: [3505147.119879]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:32:35 beosrv1-t kernel: [3505147.119907] Call Trace:

May 16 02:32:35 beosrv1-t kernel: [3505147.119924]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:32:35 beosrv1-t kernel: [3505147.119942]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:32:35 beosrv1-t kernel: [3505147.119963]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:32:35 beosrv1-t kernel: [3505147.119982]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:32:35 beosrv1-t kernel: [3505147.120000]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:32:35 beosrv1-t kernel: [3505147.120016]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:32:35 beosrv1-t kernel: [3505147.120036]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:32:35 beosrv1-t kernel: [3505147.120053]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:32:35 beosrv1-t kernel: [3505147.120070]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:32:35 beosrv1-t kernel: [3505147.120102]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:32:35 beosrv1-t kernel: [3505147.120137]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:32:35 beosrv1-t kernel: [3505147.120171]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:32:35 beosrv1-t kernel: [3505147.120203]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:32:35 beosrv1-t kernel: [3505147.120234]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:34:35 beosrv1-t kernel: [3505266.888143] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:34:35 beosrv1-t kernel: [3505266.888168]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:34:35 beosrv1-t kernel: [3505266.888197]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:34:35 beosrv1-t kernel: [3505266.888225]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:34:35 beosrv1-t kernel: [3505266.888253] Call Trace:

May 16 02:34:35 beosrv1-t kernel: [3505266.888270]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:34:35 beosrv1-t kernel: [3505266.888288]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:34:35 beosrv1-t kernel: [3505266.888309]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:34:35 beosrv1-t kernel: [3505266.888327]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:34:35 beosrv1-t kernel: [3505266.888345]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:34:35 beosrv1-t kernel: [3505266.888361]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:34:35 beosrv1-t kernel: [3505266.888381]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:34:35 beosrv1-t kernel: [3505266.888398]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:34:35 beosrv1-t kernel: [3505266.888415]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:34:35 beosrv1-t kernel: [3505266.888447]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:34:35 beosrv1-t kernel: [3505266.888482]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:34:35 beosrv1-t kernel: [3505266.888517]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:34:35 beosrv1-t kernel: [3505266.888548]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:34:35 beosrv1-t kernel: [3505266.888579]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:36:35 beosrv1-t kernel: [3505386.656500] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:36:35 beosrv1-t kernel: [3505386.656525]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:36:35 beosrv1-t kernel: [3505386.656553]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:36:35 beosrv1-t kernel: [3505386.656581]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:36:35 beosrv1-t kernel: [3505386.656609] Call Trace:

May 16 02:36:35 beosrv1-t kernel: [3505386.656626]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:36:35 beosrv1-t kernel: [3505386.656644]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:36:35 beosrv1-t kernel: [3505386.656666]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:36:35 beosrv1-t kernel: [3505386.656684]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:36:35 beosrv1-t kernel: [3505386.656701]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:36:35 beosrv1-t kernel: [3505386.656717]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:36:35 beosrv1-t kernel: [3505386.656737]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:36:35 beosrv1-t kernel: [3505386.656754]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:36:35 beosrv1-t kernel: [3505386.656771]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:36:35 beosrv1-t kernel: [3505386.656803]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:36:35 beosrv1-t kernel: [3505386.656838]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:36:35 beosrv1-t kernel: [3505386.656872]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:36:35 beosrv1-t kernel: [3505386.656904]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:36:35 beosrv1-t kernel: [3505386.656935]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:38:35 beosrv1-t kernel: [3505506.424861] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:38:35 beosrv1-t kernel: [3505506.424886]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:38:35 beosrv1-t kernel: [3505506.424915]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:38:35 beosrv1-t kernel: [3505506.424943]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:38:35 beosrv1-t kernel: [3505506.424971] Call Trace:

May 16 02:38:35 beosrv1-t kernel: [3505506.424988]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:38:35 beosrv1-t kernel: [3505506.425006]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:38:35 beosrv1-t kernel: [3505506.425027]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:38:35 beosrv1-t kernel: [3505506.425045]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:38:35 beosrv1-t kernel: [3505506.425063]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:38:35 beosrv1-t kernel: [3505506.425079]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:38:35 beosrv1-t kernel: [3505506.425099]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:38:35 beosrv1-t kernel: [3505506.425116]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:38:35 beosrv1-t kernel: [3505506.425134]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:38:35 beosrv1-t kernel: [3505506.425165]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:38:35 beosrv1-t kernel: [3505506.425200]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:38:35 beosrv1-t kernel: [3505506.425235]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:38:35 beosrv1-t kernel: [3505506.425266]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:38:35 beosrv1-t kernel: [3505506.425298]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:40:35 beosrv1-t kernel: [3505626.404818] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:40:35 beosrv1-t kernel: [3505626.404843]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:40:35 beosrv1-t kernel: [3505626.404872]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:40:35 beosrv1-t kernel: [3505626.404900]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:40:35 beosrv1-t kernel: [3505626.404928] Call Trace:

May 16 02:40:35 beosrv1-t kernel: [3505626.404945]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:40:35 beosrv1-t kernel: [3505626.404963]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:40:35 beosrv1-t kernel: [3505626.404984]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:40:35 beosrv1-t kernel: [3505626.405002]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:40:35 beosrv1-t kernel: [3505626.405020]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:40:35 beosrv1-t kernel: [3505626.405036]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:40:35 beosrv1-t kernel: [3505626.405056]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:40:35 beosrv1-t kernel: [3505626.405073]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:40:35 beosrv1-t kernel: [3505626.405091]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:40:35 beosrv1-t kernel: [3505626.405122]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:40:35 beosrv1-t kernel: [3505626.405157]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:40:35 beosrv1-t kernel: [3505626.405192]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:40:35 beosrv1-t kernel: [3505626.405223]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:40:35 beosrv1-t kernel: [3505626.405255]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b

May 16 02:42:36 beosrv1-t kernel: [3505746.348825] pv            D ffffffffffffffff     0 20917  10814 0x00000000

May 16 02:42:36 beosrv1-t kernel: [3505746.348849]  ffff8806e77f5c88 0000000000000082 ffff8806e77f5be8 ffffffff8102e847

May 16 02:42:36 beosrv1-t kernel: [3505746.348879]  000000000000dd08 ffff8806e77f5fd8 00000000000115c0 00000000000115c0

May 16 02:42:36 beosrv1-t kernel: [3505746.348907]  ffff8806554515c0 0000000000000005 ffff88024818ccd0 ffff880c3b9cc6b0

May 16 02:42:36 beosrv1-t kernel: [3505746.348935] Call Trace:

May 16 02:42:36 beosrv1-t kernel: [3505746.348952]  [<ffffffff8102e847>] ? enqueue_task_fair+0x16d/0x17a

May 16 02:42:36 beosrv1-t kernel: [3505746.348970]  [<ffffffff8102c6c4>] ? mutex_spin_on_owner+0x50/0x61

May 16 02:42:36 beosrv1-t kernel: [3505746.348991]  [<ffffffff813dd999>] __mutex_lock_slowpath+0xe9/0x133

May 16 02:42:36 beosrv1-t kernel: [3505746.349009]  [<ffffffff813dd81a>] mutex_lock+0x16/0x2d

May 16 02:42:36 beosrv1-t kernel: [3505746.349027]  [<ffffffff810a2175>] pipe_read+0x7d/0x3a8

May 16 02:42:36 beosrv1-t kernel: [3505746.349044]  [<ffffffff810a9850>] ? core_sys_select+0x200/0x254

May 16 02:42:36 beosrv1-t kernel: [3505746.349063]  [<ffffffff8109b03f>] do_sync_read+0xe7/0x12d

May 16 02:42:36 beosrv1-t kernel: [3505746.349080]  [<ffffffff81049a8f>] ? remove_wait_queue+0x48/0x4d

May 16 02:42:36 beosrv1-t kernel: [3505746.349098]  [<ffffffff8104fc7b>] ? ktime_get+0x65/0xc4

May 16 02:42:36 beosrv1-t kernel: [3505746.349129]  [<ffffffff81049828>] ? autoremove_wake_function+0x0/0x38

May 16 02:42:36 beosrv1-t kernel: [3505746.349164]  [<ffffffff810a87e0>] ? poll_select_copy_remaining+0xc5/0xea

May 16 02:42:36 beosrv1-t kernel: [3505746.349199]  [<ffffffff8109ba86>] vfs_read+0xab/0x147

May 16 02:42:36 beosrv1-t kernel: [3505746.349230]  [<ffffffff8109bbe6>] sys_read+0x47/0x6f

May 16 02:42:36 beosrv1-t kernel: [3505746.349261]  [<ffffffff8100af2b>] system_call_fastpath+0x16/0x1b


[-- Attachment #3: Type: TEXT/PLAIN, Size: 4545 bytes --]

#Time      PID  User     PR  PPID THRD S   VSZ   RSS CP  SysT  UsrT Pct  AccuTime MajF MinF Command

01:46:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0

01:46:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1

01:47:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0

01:47:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1

01:48:00    77  root     20     2    0 S     0     0  3  0.00  0.00   0 386:07.51    0    0 kswapd0

01:48:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.25    0    0 kswapd1

01:49:00    77  root     20     2    0 R     0     0  2 55.48  0.00  92 387:02.99    0    0 kswapd0

01:49:00    78  root     20     2    0 S     0     0  7  0.70  0.00   1 305:02.95    0    0 kswapd1

01:50:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 388:02.87    0    0 kswapd0

01:50:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:51:00    77  root     20     2    0 R     0     0  2 59.86  0.00  99 389:02.73    0    0 kswapd0

01:51:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:52:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 390:02.62    0    0 kswapd0

01:52:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:53:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 391:02.51    0    0 kswapd0

01:53:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:54:00    77  root     20     2    0 R     0     0  2 59.11  0.00  98 392:01.62    0    0 kswapd0

01:54:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:55:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 393:01.50    0    0 kswapd0

01:55:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:56:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 394:01.39    0    0 kswapd0

01:56:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:57:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 395:01.28    0    0 kswapd0

01:57:00    78  root     20     2    0 S     0     0  7  0.00  0.00   0 305:02.95    0    0 kswapd1

01:58:00    77  root     20     2    0 R     0     0  2 59.96  0.00  99 396:01.24    0    0 kswapd0

01:58:00    78  root     20     2    0 R     0     0  7 38.42  0.00  64 305:41.37    0    0 kswapd1

01:59:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 397:01.13    0    0 kswapd0

01:59:00    78  root     20     2    0 R     0     0  7 59.84  0.00  99 306:41.21    0    0 kswapd1

02:00:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 398:01.01    0    0 kswapd0

02:00:00    78  root     20     2    0 R     0     0  7 59.88  0.00  99 307:41.09    0    0 kswapd1

02:01:00    77  root     20     2    0 R     0     0  2 59.77  0.00  99 399:00.78    0    0 kswapd0

02:01:00    78  root     20     2    0 R     0     0  7 59.80  0.00  99 308:40.89    0    0 kswapd1

02:02:00    77  root     20     2    0 R     0     0  2 59.88  0.00  99 400:00.66    0    0 kswapd0

02:02:00    78  root     20     2    0 R     0     0  7 59.88  0.00  99 309:40.77    0    0 kswapd1

02:03:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 401:00.55    0    0 kswapd0

02:03:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 310:40.66    0    0 kswapd1

02:04:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 402:00.44    0    0 kswapd0

02:04:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 311:40.55    0    0 kswapd1

02:05:00    77  root     20     2    0 R     0     0  2 59.89  0.00  99 403:00.33    0    0 kswapd0

02:05:00    78  root     20     2    0 R     0     0  7 59.89  0.00  99 312:40.44    0    0 kswapd1

02:06:00    77  root     20     2    0 R     0     0  3 59.87  0.00  99 404:00.20    0    0 kswapd0

02:06:00    78  root     20     2    0 R     0     0  5 59.87  0.00  99 313:40.31    0    0 kswapd1

02:07:00    77  root     20     2    0 R     0     0  3 59.90  0.00  99 405:00.10    0    0 kswapd0

02:07:00    78  root     20     2    0 R     0     0  5 59.90  0.00  99 314:40.21    0    0 kswapd1


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-05-19 16:00                                   ` Christoph Lameter
@ 2011-05-23  6:34                                     ` Peter Kruse
  0 siblings, 0 replies; 27+ messages in thread
From: Peter Kruse @ 2011-05-23  6:34 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: David Rientjes, eric.dumazet, linux-kernel

[-- Attachment #1: Type: text/plain, Size: 398 bytes --]

Hi Christoph,

On 05/19/2011 06:00 PM, Christoph Lameter wrote:
> 
> We need the complete system log starting from bootup.
> 
> This looks like it has something to do with mutexes and pipes.

ah yes, I was told that there was a program running that sent
a large file to a pipe.
Attaching dmesg from the boot after the server was reset
and the kern.log from the boot before.

Best regards,

  Peter

[-- Attachment #2: dmesg --]
[-- Type: text/plain, Size: 56548 bytes --]

[    0.000000] Linux version 2.6.32.29-ql-server-20 (root@ql-dev) (gcc version 4.3.2 (Debian 4.3.2-1.1) ) #1 SMP Wed Feb 23 14:20:09 CET 2011
[    0.000000] Command line: auto BOOT_IMAGE=linux ro root=100 root=/dev/mapper/vgroot-root elevator=cfq
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Centaur CentaurHauls
[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  BIOS-e820: 0000000000000000 - 0000000000097c00 (usable)
[    0.000000]  BIOS-e820: 0000000000097c00 - 00000000000a0000 (reserved)
[    0.000000]  BIOS-e820: 00000000000e6000 - 0000000000100000 (reserved)
[    0.000000]  BIOS-e820: 0000000000100000 - 00000000bf780000 (usable)
[    0.000000]  BIOS-e820: 00000000bf78e000 - 00000000bf790000 type 9
[    0.000000]  BIOS-e820: 00000000bf790000 - 00000000bf79e000 (ACPI data)
[    0.000000]  BIOS-e820: 00000000bf79e000 - 00000000bf7d0000 (ACPI NVS)
[    0.000000]  BIOS-e820: 00000000bf7d0000 - 00000000bf7e0000 (reserved)
[    0.000000]  BIOS-e820: 00000000bf7ec000 - 00000000c0000000 (reserved)
[    0.000000]  BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
[    0.000000]  BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
[    0.000000]  BIOS-e820: 00000000ffc00000 - 0000000100000000 (reserved)
[    0.000000]  BIOS-e820: 0000000100000000 - 0000000c40000000 (usable)
[    0.000000] DMI present.
[    0.000000] AMI BIOS detected: BIOS may corrupt low RAM, working around it.
[    0.000000] e820 update range: 0000000000000000 - 0000000000010000 (usable) ==> (reserved)
[    0.000000] last_pfn = 0xc40000 max_arch_pfn = 0x400000000
[    0.000000] MTRR default type: uncachable
[    0.000000] MTRR fixed ranges enabled:
[    0.000000]   00000-9FFFF write-back
[    0.000000]   A0000-BFFFF uncachable
[    0.000000]   C0000-D7FFF write-protect
[    0.000000]   D8000-DFFFF uncachable
[    0.000000]   E0000-E3FFF write-protect
[    0.000000]   E4000-EBFFF write-through
[    0.000000]   EC000-FFFFF write-protect
[    0.000000] MTRR variable ranges enabled:
[    0.000000]   0 base 0000000000 mask F800000000 write-back
[    0.000000]   1 base 0800000000 mask FC00000000 write-back
[    0.000000]   2 base 0C00000000 mask FFC0000000 write-back
[    0.000000]   3 base 00C0000000 mask FFC0000000 uncachable
[    0.000000]   4 base 00BF800000 mask FFFF800000 uncachable
[    0.000000]   5 disabled
[    0.000000]   6 disabled
[    0.000000]   7 disabled
[    0.000000] e820 update range: 00000000bf800000 - 0000000100000000 (usable) ==> (reserved)
[    0.000000] last_pfn = 0xbf780 max_arch_pfn = 0x400000000
[    0.000000] initial memory mapped : 0 - 20000000
[    0.000000] init_memory_mapping: 0000000000000000-00000000bf780000
[    0.000000]  0000000000 - 00bf600000 page 2M
[    0.000000]  00bf600000 - 00bf780000 page 4k
[    0.000000] kernel direct mapping tables up to bf780000 @ 10000-15000
[    0.000000] init_memory_mapping: 0000000100000000-0000000c40000000
[    0.000000]  0100000000 - 0c40000000 page 2M
[    0.000000] kernel direct mapping tables up to c40000000 @ 13000-45000
[    0.000000] RAMDISK: 03c83000 - 040feff0
[    0.000000] ACPI: RSDP 00000000000f9c40 00024 (v02 ACPIAM)
[    0.000000] ACPI: XSDT 00000000bf790100 0007C (v01 100709 XSDT1044 20091007 MSFT 00000097)
[    0.000000] ACPI: FACP 00000000bf790290 000F4 (v04 100709 FACP1044 20091007 MSFT 00000097)
[    0.000000] ACPI: DSDT 00000000bf7904c0 0597A (v02  1F280 1F280000 00000000 INTL 20051117)
[    0.000000] ACPI: FACS 00000000bf79e000 00040
[    0.000000] ACPI: APIC 00000000bf790390 000EA (v02 100709 APIC1044 20091007 MSFT 00000097)
[    0.000000] ACPI: MCFG 00000000bf790480 0003C (v01 100709 OEMMCFG  20091007 MSFT 00000097)
[    0.000000] ACPI: OEMB 00000000bf79e040 0007A (v01 100709 OEMB1044 20091007 MSFT 00000097)
[    0.000000] ACPI: SRAT 00000000bf79a4c0 00150 (v02 100709 OEMSRAT  00000001 INTL 00000001)
[    0.000000] ACPI: DMAR 00000000bf79e0c0 00128 (v01    AMI  OEMDMAR 00000001 MSFT 00000097)
[    0.000000] ACPI: SSDT 00000000bf79f800 00363 (v01 DpgPmm    CpuPm 00000012 INTL 20051117)
[    0.000000] ACPI: EINJ 00000000bf79a610 00130 (v01  AMIER AMI_EINJ 20091007 MSFT 00000097)
[    0.000000] ACPI: BERT 00000000bf79a7a0 00030 (v01  AMIER AMI_BERT 20091007 MSFT 00000097)
[    0.000000] ACPI: ERST 00000000bf79a7d0 001B0 (v01  AMIER AMI_ERST 20091007 MSFT 00000097)
[    0.000000] ACPI: HEST 00000000bf79a980 000A8 (v01  AMIER ABC_HEST 20091007 MSFT 00000097)
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] SRAT: PXM 0 -> APIC 0 -> Node 0
[    0.000000] SRAT: PXM 0 -> APIC 2 -> Node 0
[    0.000000] SRAT: PXM 0 -> APIC 4 -> Node 0
[    0.000000] SRAT: PXM 0 -> APIC 6 -> Node 0
[    0.000000] SRAT: PXM 1 -> APIC 16 -> Node 1
[    0.000000] SRAT: PXM 1 -> APIC 18 -> Node 1
[    0.000000] SRAT: PXM 1 -> APIC 20 -> Node 1
[    0.000000] SRAT: PXM 1 -> APIC 22 -> Node 1
[    0.000000] SRAT: Node 0 PXM 0 0-a0000
[    0.000000] SRAT: Node 0 PXM 0 100000-c0000000
[    0.000000] SRAT: Node 0 PXM 0 100000000-640000000
[    0.000000] SRAT: Node 1 PXM 1 640000000-c40000000
[    0.000000] NUMA: Allocated memnodemap from 40000 - 58840
[    0.000000] NUMA: Using 20 for the hash shift.
[    0.000000] Bootmem setup node 0 0000000000000000-0000000640000000
[    0.000000]   NODE_DATA [0000000000058840 - 000000000005d83f]
[    0.000000]   bootmap [0000000000100000 -  00000000001c7fff] pages c8
[    0.000000] (9 early reservations) ==> bootmem [0000000000 - 0640000000]
[    0.000000]   #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
[    0.000000]   #1 [0000006000 - 0000008000]       TRAMPOLINE ==> [0000006000 - 0000008000]
[    0.000000]   #2 [0001000000 - 0001899604]    TEXT DATA BSS ==> [0001000000 - 0001899604]
[    0.000000]   #3 [0003c83000 - 00040feff0]          RAMDISK ==> [0003c83000 - 00040feff0]
[    0.000000]   #4 [0000097c00 - 0000100000]    BIOS reserved ==> [0000097c00 - 0000100000]
[    0.000000]   #5 [000189a000 - 000189a1b8]              BRK ==> [000189a000 - 000189a1b8]
[    0.000000]   #6 [0000010000 - 0000013000]          PGTABLE ==> [0000010000 - 0000013000]
[    0.000000]   #7 [0000013000 - 0000040000]          PGTABLE ==> [0000013000 - 0000040000]
[    0.000000]   #8 [0000040000 - 0000058840]       MEMNODEMAP ==> [0000040000 - 0000058840]
[    0.000000] Bootmem setup node 1 0000000640000000-0000000c40000000
[    0.000000]   NODE_DATA [0000000640000000 - 0000000640004fff]
[    0.000000]   bootmap [0000000640005000 -  00000006400c4fff] pages c0
[    0.000000] (9 early reservations) ==> bootmem [0640000000 - 0c40000000]
[    0.000000]   #0 [0000000000 - 0000001000]   BIOS data page
[    0.000000]   #1 [0000006000 - 0000008000]       TRAMPOLINE
[    0.000000]   #2 [0001000000 - 0001899604]    TEXT DATA BSS
[    0.000000]   #3 [0003c83000 - 00040feff0]          RAMDISK
[    0.000000]   #4 [0000097c00 - 0000100000]    BIOS reserved
[    0.000000]   #5 [000189a000 - 000189a1b8]              BRK
[    0.000000]   #6 [0000010000 - 0000013000]          PGTABLE
[    0.000000]   #7 [0000013000 - 0000040000]          PGTABLE
[    0.000000]   #8 [0000040000 - 0000058840]       MEMNODEMAP
[    0.000000] found SMP MP-table at [ffff8800000ff780] ff780
[    0.000000]  [ffffea0000000000-ffffea0015dfffff] PMD -> [ffff880028600000-ffff88003d5fffff] on node 0
[    0.000000]  [ffffea0015e00000-ffffea002adfffff] PMD -> [ffff880640200000-ffff8806551fffff] on node 1
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA      0x00000010 -> 0x00001000
[    0.000000]   DMA32    0x00001000 -> 0x00100000
[    0.000000]   Normal   0x00100000 -> 0x00c40000
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[4] active PFN ranges
[    0.000000]     0: 0x00000010 -> 0x00000097
[    0.000000]     0: 0x00000100 -> 0x000bf780
[    0.000000]     0: 0x00100000 -> 0x00640000
[    0.000000]     1: 0x00640000 -> 0x00c40000
[    0.000000] On node 0 totalpages: 6289159
[    0.000000]   DMA zone: 56 pages used for memmap
[    0.000000]   DMA zone: 179 pages reserved
[    0.000000]   DMA zone: 3740 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 14280 pages used for memmap
[    0.000000]   DMA32 zone: 765880 pages, LIFO batch:31
[    0.000000]   Normal zone: 75264 pages used for memmap
[    0.000000]   Normal zone: 5429760 pages, LIFO batch:31
[    0.000000] On node 1 totalpages: 6291456
[    0.000000]   Normal zone: 86016 pages used for memmap
[    0.000000]   Normal zone: 6205440 pages, LIFO batch:31
[    0.000000] ACPI: PM-Timer IO Port: 0x808
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x04] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x06] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x05] lapic_id[0x10] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x06] lapic_id[0x12] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x07] lapic_id[0x14] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x08] lapic_id[0x16] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x09] lapic_id[0x88] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0a] lapic_id[0x89] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0b] lapic_id[0x8a] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0c] lapic_id[0x8b] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0d] lapic_id[0x8c] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0e] lapic_id[0x8d] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0f] lapic_id[0x8e] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x10] lapic_id[0x8f] disabled)
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
[    0.000000] IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: IOAPIC (id[0x03] address[0xfec80000] gsi_base[24])
[    0.000000] IOAPIC[1]: apic_id 3, version 32, address 0xfec80000, GSI 24-47
[    0.000000] ACPI: IOAPIC (id[0x05] address[0xfec80400] gsi_base[48])
[    0.000000] IOAPIC[2]: apic_id 5, version 32, address 0xfec80400, GSI 48-71
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ2 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] SMP: Allowing 16 CPUs, 8 hotplug CPUs
[    0.000000] nr_irqs_gsi: 72
[    0.000000] Allocating PCI resources starting at c0000000 (gap: c0000000:20000000)
[    0.000000] NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:16 nr_node_ids:2
[    0.000000] PERCPU: Embedded 25 pages/cpu @ffff880028200000 s73240 r8192 d20968 u262144
[    0.000000] pcpu-alloc: s73240 r8192 d20968 u262144 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 00 01 02 03 08 10 12 14 [1] 04 05 06 07 09 11 13 15 
[    0.000000] Built 2 zonelists in Zone order, mobility grouping on.  Total pages: 12404820
[    0.000000] Policy zone: Normal
[    0.000000] Kernel command line: auto BOOT_IMAGE=linux ro root=100 root=/dev/mapper/vgroot-root elevator=cfq
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Initializing CPU#0
[    0.000000] Checking aperture...
[    0.000000] No AGP bridge found
[    0.000000] Calgary: detecting Calgary via BIOS EBDA area
[    0.000000] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
[    0.000000] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    0.000000] Placing 64MB software IO TLB between ffff880020000000 - ffff880024000000
[    0.000000] software IO TLB at phys 0x20000000 - 0x24000000
[    0.000000] Memory: 49552644k/51380224k available (3972k kernel code, 1057764k absent, 769816k reserved, 2393k data, 516k init)
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS:2304
[    0.000000] Extended CMOS year: 2000
[    0.000000] Console: colour VGA+ 80x25
[    0.000000] console [tty0] enabled
[    0.000000] Fast TSC calibration using PIT
[    0.004000] Detected 2000.312 MHz processor.
[    0.000007] Calibrating delay loop (skipped), value calculated using timer frequency.. 4000.62 BogoMIPS (lpj=8001248)
[    0.005108] Dentry cache hash table entries: 8388608 (order: 14, 67108864 bytes)
[    0.022008] Inode-cache hash table entries: 4194304 (order: 13, 33554432 bytes)
[    0.029345] Mount-cache hash table entries: 256
[    0.029571] CPU: Physical Processor ID: 0
[    0.029643] CPU: Processor Core ID: 0
[    0.029715] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.029836] CPU: L2 cache: 256K
[    0.029905] CPU: L3 cache: 4096K
[    0.029977] CPU 0/0x0 -> Node 0
[    0.030048] mce: CPU supports 9 MCE banks
[    0.030129] CPU0: Thermal monitoring enabled (TM1)
[    0.030204] CPU 0 MCA banks CMCI:2 CMCI:3 CMCI:5 CMCI:6 SHD:8
[    0.030567] using mwait in idle threads.
[    0.030638] Performance Events: Nehalem/Corei7 events, Intel PMU driver.
[    0.030813] ... version:                3
[    0.030884] ... bit width:              48
[    0.030956] ... generic registers:      4
[    0.031027] ... value mask:             0000ffffffffffff
[    0.031102] ... max period:             000000007fffffff
[    0.031176] ... fixed-purpose events:   3
[    0.031248] ... event mask:             000000070000000f
[    0.031340] ACPI: Core revision 20090903
[    0.041731] Setting APIC routing to physical flat
[    0.042353] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.088786] CPU0: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.196236] Booting processor 1 APIC 0x2 ip 0x6000
[    0.206615] Initializing CPU#1
[    0.283940] CPU: Physical Processor ID: 0
[    0.283942] CPU: Processor Core ID: 1
[    0.283944] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.283946] CPU: L2 cache: 256K
[    0.283947] CPU: L3 cache: 4096K
[    0.283949] CPU 1/0x2 -> Node 0
[    0.283962] CPU1: Thermal monitoring enabled (TM1)
[    0.283965] CPU 1 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.283988] CPU1: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.284796] checking TSC synchronization [CPU#0 -> CPU#1]: passed.
[    0.305062] Booting processor 2 APIC 0x4 ip 0x6000
[    0.315316] Initializing CPU#2
[    0.395727] CPU: Physical Processor ID: 0
[    0.395728] CPU: Processor Core ID: 2
[    0.395731] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.395733] CPU: L2 cache: 256K
[    0.395734] CPU: L3 cache: 4096K
[    0.395736] CPU 2/0x4 -> Node 0
[    0.395749] CPU2: Thermal monitoring enabled (TM1)
[    0.395752] CPU 2 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.395784] CPU2: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.396592] checking TSC synchronization [CPU#0 -> CPU#2]: passed.
[    0.416859] Booting processor 3 APIC 0x6 ip 0x6000
[    0.427114] Initializing CPU#3
[    0.507514] CPU: Physical Processor ID: 0
[    0.507515] CPU: Processor Core ID: 3
[    0.507518] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.507519] CPU: L2 cache: 256K
[    0.507521] CPU: L3 cache: 4096K
[    0.507523] CPU 3/0x6 -> Node 0
[    0.507536] CPU3: Thermal monitoring enabled (TM1)
[    0.507539] CPU 3 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.507581] CPU3: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.508390] checking TSC synchronization [CPU#0 -> CPU#3]: passed.
[    0.528717] Booting processor 4 APIC 0x10 ip 0x6000
[    0.538971] Initializing CPU#4
[    0.619301] CPU: Physical Processor ID: 1
[    0.619302] CPU: Processor Core ID: 0
[    0.619304] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.619306] CPU: L2 cache: 256K
[    0.619307] CPU: L3 cache: 4096K
[    0.619310] CPU 4/0x10 -> Node 1
[    0.619322] CPU4: Thermal monitoring enabled (TM1)
[    0.619326] CPU 4 MCA banks CMCI:2 CMCI:3 CMCI:5 CMCI:6 SHD:8
[    0.619339] CPU4: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.620147] checking TSC synchronization [CPU#0 -> CPU#4]: passed.
[    0.640437] Booting processor 5 APIC 0x12 ip 0x6000
[    0.650693] Initializing CPU#5
[    0.731089] CPU: Physical Processor ID: 1
[    0.731091] CPU: Processor Core ID: 1
[    0.731093] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.731095] CPU: L2 cache: 256K
[    0.731097] CPU: L3 cache: 4096K
[    0.731099] CPU 5/0x12 -> Node 1
[    0.731114] CPU5: Thermal monitoring enabled (TM1)
[    0.731117] CPU 5 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.731211] CPU5: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.732020] checking TSC synchronization [CPU#0 -> CPU#5]: passed.
[    0.752332] Booting processor 6 APIC 0x14 ip 0x6000
[    0.762589] Initializing CPU#6
[    0.842876] CPU: Physical Processor ID: 1
[    0.842877] CPU: Processor Core ID: 2
[    0.842880] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.842882] CPU: L2 cache: 256K
[    0.842883] CPU: L3 cache: 4096K
[    0.842886] CPU 6/0x14 -> Node 1
[    0.842900] CPU6: Thermal monitoring enabled (TM1)
[    0.842904] CPU 6 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.842954] CPU6: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.843762] checking TSC synchronization [CPU#0 -> CPU#6]: passed.
[    0.864070] Booting processor 7 APIC 0x16 ip 0x6000
[    0.874326] Initializing CPU#7
[    0.954663] CPU: Physical Processor ID: 1
[    0.954664] CPU: Processor Core ID: 3
[    0.954667] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.954669] CPU: L2 cache: 256K
[    0.954670] CPU: L3 cache: 4096K
[    0.954673] CPU 7/0x16 -> Node 1
[    0.954688] CPU7: Thermal monitoring enabled (TM1)
[    0.954691] CPU 7 MCA banks CMCI:2 CMCI:3 CMCI:5 SHD:6 SHD:8
[    0.954721] CPU7: Intel(R) Xeon(R) CPU           E5504  @ 2.00GHz stepping 05
[    0.955529] checking TSC synchronization [CPU#0 -> CPU#7]: passed.
[    0.975706] Brought up 8 CPUs
[    0.975777] Total of 8 processors activated (32002.46 BogoMIPS).
[    0.978606] xor: automatically using best checksumming function: generic_sse
[    0.998582]    generic_sse:  7445.000 MB/sec
[    0.998655] xor: using function: generic_sse (7445.000 MB/sec)
[    0.998805] NET: Registered protocol family 16
[    0.998970] ACPI: bus type pci registered
[    0.999085] PCI: Using configuration type 1 for base access
[    1.000173] bio: create slab <bio-0> at 0
[    1.001130] ACPI: EC: Look up EC in DSDT
[    1.003890] ACPI Warning for \_SB_._OSC: Return type mismatch - found Integer, expected Buffer (20090903/nspredef-1006)
[    1.004092] \_SB_:_OSC evaluation returned wrong type
[    1.004094] _OSC request data:1 6 
[    1.004603] ACPI: Executed 1 blocks of module-level executable AML code
[    1.012316] ACPI: Interpreter enabled
[    1.012389] ACPI: (supports S0 S1 S5)
[    1.012619] ACPI: Using IOAPIC for interrupt routing
[    1.023502] ACPI Warning: Incorrect checksum in table [OEMB] - 0A, should be FF (20090903/tbutils-314)
[    1.024009] ACPI: No dock devices found.
[    1.024258] ACPI: PCI Root Bridge [PCI0] (0000:00)
[    1.024417] pci 0000:00:00.0: PME# supported from D0 D3hot D3cold
[    1.024496] pci 0000:00:00.0: PME# disabled
[    1.024630] pci 0000:00:01.0: PME# supported from D0 D3hot D3cold
[    1.024708] pci 0000:00:01.0: PME# disabled
[    1.024844] pci 0000:00:03.0: PME# supported from D0 D3hot D3cold
[    1.024922] pci 0000:00:03.0: PME# disabled
[    1.025058] pci 0000:00:05.0: PME# supported from D0 D3hot D3cold
[    1.025136] pci 0000:00:05.0: PME# disabled
[    1.025272] pci 0000:00:07.0: PME# supported from D0 D3hot D3cold
[    1.025350] pci 0000:00:07.0: PME# disabled
[    1.025485] pci 0000:00:09.0: PME# supported from D0 D3hot D3cold
[    1.025563] pci 0000:00:09.0: PME# disabled
[    1.025999] pci 0000:00:16.0: reg 10 64bit mmio: [0xfb8d8000-0xfb8dbfff]
[    1.026063] pci 0000:00:16.1: reg 10 64bit mmio: [0xfb8dc000-0xfb8dffff]
[    1.026126] pci 0000:00:16.2: reg 10 64bit mmio: [0xfb8e0000-0xfb8e3fff]
[    1.026190] pci 0000:00:16.3: reg 10 64bit mmio: [0xfb8e4000-0xfb8e7fff]
[    1.026253] pci 0000:00:16.4: reg 10 64bit mmio: [0xfb8e8000-0xfb8ebfff]
[    1.026316] pci 0000:00:16.5: reg 10 64bit mmio: [0xfb8ec000-0xfb8effff]
[    1.026380] pci 0000:00:16.6: reg 10 64bit mmio: [0xfb8f0000-0xfb8f3fff]
[    1.026443] pci 0000:00:16.7: reg 10 64bit mmio: [0xfb8f4000-0xfb8f7fff]
[    1.026528] pci 0000:00:1a.0: reg 20 io port: [0x9400-0x941f]
[    1.026601] pci 0000:00:1a.1: reg 20 io port: [0x9480-0x949f]
[    1.026669] pci 0000:00:1a.2: reg 20 io port: [0x9800-0x981f]
[    1.026743] pci 0000:00:1a.7: reg 10 32bit mmio: [0xfb8fa000-0xfb8fa3ff]
[    1.026797] pci 0000:00:1a.7: PME# supported from D0 D3hot D3cold
[    1.026876] pci 0000:00:1a.7: PME# disabled
[    1.027008] pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
[    1.027086] pci 0000:00:1c.0: PME# disabled
[    1.027222] pci 0000:00:1c.4: PME# supported from D0 D3hot D3cold
[    1.027300] pci 0000:00:1c.4: PME# disabled
[    1.027424] pci 0000:00:1d.0: reg 20 io port: [0x9880-0x989f]
[    1.027493] pci 0000:00:1d.1: reg 20 io port: [0x9c00-0x9c1f]
[    1.027562] pci 0000:00:1d.2: reg 20 io port: [0xa000-0xa01f]
[    1.027634] pci 0000:00:1d.7: reg 10 32bit mmio: [0xfb8fc000-0xfb8fc3ff]
[    1.027688] pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
[    1.027766] pci 0000:00:1d.7: PME# disabled
[    1.027965] pci 0000:00:1f.0: Force enabled HPET at 0xfed00000
[    1.027969] pci 0000:00:1f.0: quirk: region 0800-087f claimed by ICH6 ACPI/GPIO/TCO
[    1.028066] pci 0000:00:1f.0: quirk: region 0500-053f claimed by ICH6 GPIO
[    1.028146] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 1 PIO at 0a00 (mask 00ff)
[    1.028244] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 3 PIO at 0290 (mask 001f)
[    1.028341] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 4 PIO at 0ca0 (mask 000f)
[    1.028486] pci 0000:00:1f.2: reg 10 io port: [0xbc00-0xbc07]
[    1.028491] pci 0000:00:1f.2: reg 14 io port: [0xb880-0xb883]
[    1.028497] pci 0000:00:1f.2: reg 18 io port: [0xb800-0xb807]
[    1.028502] pci 0000:00:1f.2: reg 1c io port: [0xb480-0xb483]
[    1.028508] pci 0000:00:1f.2: reg 20 io port: [0xb400-0xb40f]
[    1.028513] pci 0000:00:1f.2: reg 24 io port: [0xb080-0xb08f]
[    1.028559] pci 0000:00:1f.3: reg 10 64bit mmio: [0xfb8fe000-0xfb8fe0ff]
[    1.028572] pci 0000:00:1f.3: reg 20 io port: [0x400-0x41f]
[    1.028616] pci 0000:00:1f.5: reg 10 io port: [0xac00-0xac07]
[    1.028622] pci 0000:00:1f.5: reg 14 io port: [0xa880-0xa883]
[    1.028627] pci 0000:00:1f.5: reg 18 io port: [0xa800-0xa807]
[    1.028632] pci 0000:00:1f.5: reg 1c io port: [0xa480-0xa483]
[    1.028638] pci 0000:00:1f.5: reg 20 io port: [0xa400-0xa40f]
[    1.028643] pci 0000:00:1f.5: reg 24 io port: [0xa080-0xa08f]
[    1.028711] pci 0000:0a:00.0: reg 10 32bit mmio: [0xfbe60000-0xfbe7ffff]
[    1.028717] pci 0000:0a:00.0: reg 14 32bit mmio: [0xfbe40000-0xfbe5ffff]
[    1.028724] pci 0000:0a:00.0: reg 18 io port: [0xe880-0xe89f]
[    1.028730] pci 0000:0a:00.0: reg 1c 32bit mmio: [0xfbe1c000-0xfbe1ffff]
[    1.028745] pci 0000:0a:00.0: reg 30 32bit mmio pref: [0xfbe20000-0xfbe3ffff]
[    1.028774] pci 0000:0a:00.0: PME# supported from D0 D3hot D3cold
[    1.028853] pci 0000:0a:00.0: PME# disabled
[    1.028968] pci 0000:0a:00.1: reg 10 32bit mmio: [0xfbee0000-0xfbefffff]
[    1.028975] pci 0000:0a:00.1: reg 14 32bit mmio: [0xfbec0000-0xfbedffff]
[    1.028981] pci 0000:0a:00.1: reg 18 io port: [0xec00-0xec1f]
[    1.028988] pci 0000:0a:00.1: reg 1c 32bit mmio: [0xfbe9c000-0xfbe9ffff]
[    1.029002] pci 0000:0a:00.1: reg 30 32bit mmio pref: [0xfbea0000-0xfbebffff]
[    1.029032] pci 0000:0a:00.1: PME# supported from D0 D3hot D3cold
[    1.029110] pci 0000:0a:00.1: PME# disabled
[    1.029217] pci 0000:00:01.0: bridge io port: [0xe000-0xefff]
[    1.029220] pci 0000:00:01.0: bridge 32bit mmio: [0xfbe00000-0xfbefffff]
[    1.029259] pci 0000:09:00.0: reg 10 64bit mmio: [0xfbc00000-0xfbdfffff]
[    1.029281] pci 0000:09:00.0: reg 30 32bit mmio pref: [0xfbb80000-0xfbbfffff]
[    1.029305] pci 0000:09:00.0: supports D1
[    1.029335] pci 0000:00:03.0: bridge 32bit mmio: [0xfbb00000-0xfbdfffff]
[    1.029423] pci 0000:04:00.0: PXH quirk detected; SHPC device MSI disabled
[    1.029532] pci 0000:04:00.0: PME# supported from D0 D3hot D3cold
[    1.029610] pci 0000:04:00.0: PME# disabled
[    1.029715] pci 0000:04:00.2: PXH quirk detected; SHPC device MSI disabled
[    1.029823] pci 0000:04:00.2: PME# supported from D0 D3hot D3cold
[    1.029901] pci 0000:04:00.2: PME# disabled
[    1.030190] pci 0000:02:00.0: reg 10 io port: [0xd400-0xd407]
[    1.030199] pci 0000:02:00.0: reg 14 io port: [0xdc00-0xdc03]
[    1.030208] pci 0000:02:00.0: reg 18 io port: [0xd880-0xd887]
[    1.030217] pci 0000:02:00.0: reg 1c io port: [0xd800-0xd803]
[    1.030225] pci 0000:02:00.0: reg 20 io port: [0xd480-0xd48f]
[    1.030241] pci 0000:02:00.0: reg 30 32bit mmio pref: [0xfbaf0000-0xfbafffff]
[    1.030322] pci 0000:00:1c.4: bridge io port: [0xd000-0xdfff]
[    1.030326] pci 0000:00:1c.4: bridge 32bit mmio: [0xfba00000-0xfbafffff]
[    1.030366] pci 0000:01:01.0: reg 10 32bit mmio pref: [0xf0000000-0xf7ffffff]
[    1.030373] pci 0000:01:01.0: reg 14 io port: [0xc000-0xc0ff]
[    1.030380] pci 0000:01:01.0: reg 18 32bit mmio: [0xfb9d0000-0xfb9dffff]
[    1.030402] pci 0000:01:01.0: reg 30 32bit mmio pref: [0xfb9e0000-0xfb9fffff]
[    1.030421] pci 0000:01:01.0: supports D1 D2
[    1.030464] pci 0000:00:1e.0: transparent bridge
[    1.030542] pci 0000:00:1e.0: bridge io port: [0xc000-0xcfff]
[    1.030546] pci 0000:00:1e.0: bridge 32bit mmio: [0xfb900000-0xfb9fffff]
[    1.030552] pci 0000:00:1e.0: bridge 64bit mmio pref: [0xf0000000-0xf7ffffff]
[    1.030585] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[    1.030880] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.P0P1._PRT]
[    1.030998] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE1._PRT]
[    1.031064] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE3._PRT]
[    1.031131] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE5._PRT]
[    1.031196] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE7._PRT]
[    1.031261] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE9._PRT]
[    1.031330] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE9.PXHA._PRT]
[    1.031421] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.NPE9.PXHB._PRT]
[    1.031487] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.P0P4._PRT]
[    1.031564] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.P0P8._PRT]
[    1.073169] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 *7 10 11 12 14 15)
[    1.073933] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 *10 11 12 14 15)
[    1.074699] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 10 *11 12 14 15)
[    1.075459] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 *5 6 7 10 11 12 14 15)
[    1.076220] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 10 11 12 14 15) *0, disabled.
[    1.077093] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 10 11 12 *14 15)
[    1.077853] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 10 11 12 14 15) *0, disabled.
[    1.078729] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 10 11 12 14 *15)
[    1.079477] vgaarb: device added: PCI:0000:01:01.0,decodes=io+mem,owns=io+mem,locks=none
[    1.079574] vgaarb: loaded
[    1.079791] SCSI subsystem initialized
[    1.080018] libata version 3.00 loaded.
[    1.146316] raid6: int64x1   2163 MB/s
[    1.214186] raid6: int64x2   2503 MB/s
[    1.282068] raid6: int64x4   1786 MB/s
[    1.349931] raid6: int64x8   1579 MB/s
[    1.417806] raid6: sse2x1    4875 MB/s
[    1.485666] raid6: sse2x2    5617 MB/s
[    1.553538] raid6: sse2x4    6703 MB/s
[    1.553609] raid6: using algorithm sse2x4 (6703 MB/s)
[    1.553689] PCI: Using ACPI for IRQ routing
[    1.554096] hpet clockevent registered
[    1.554100] HPET: 4 timers in total, 0 timers will be used for per-cpu timer
[    1.566661] Switching to clocksource tsc
[    1.567068] pnp: PnP ACPI init
[    1.567159] ACPI: bus type pnp registered
[    1.572285] pnp: PnP ACPI: found 16 devices
[    1.572359] ACPI: ACPI bus type pnp unregistered
[    1.572442] system 00:01: iomem range 0xfbf00000-0xfbffffff has been reserved
[    1.572521] system 00:01: iomem range 0xfc000000-0xfcffffff has been reserved
[    1.572601] system 00:01: iomem range 0xfd000000-0xfdffffff has been reserved
[    1.572681] system 00:01: iomem range 0xfe000000-0xfebfffff has been reserved
[    1.572760] system 00:01: iomem range 0xfec8a000-0xfec8afff has been reserved
[    1.572840] system 00:01: iomem range 0xfed10000-0xfed10fff has been reserved
[    1.572925] system 00:09: ioport range 0x4d0-0x4d1 has been reserved
[    1.579739] system 00:09: ioport range 0x800-0x87f has been reserved
[    1.579818] system 00:09: ioport range 0x500-0x57f could not be reserved
[    1.579897] system 00:09: iomem range 0xfed1c000-0xfed1ffff has been reserved
[    1.579977] system 00:09: iomem range 0xfed20000-0xfed3ffff has been reserved
[    1.580056] system 00:09: iomem range 0xfed40000-0xfed8ffff has been reserved
[    1.580139] system 00:0a: iomem range 0xfec00000-0xfec00fff could not be reserved
[    1.580235] system 00:0a: iomem range 0xfee00000-0xfee00fff has been reserved
[    1.580318] system 00:0d: ioport range 0xa00-0xa0f has been reserved
[    1.580399] system 00:0e: iomem range 0xe0000000-0xefffffff has been reserved
[    1.580481] system 00:0f: iomem range 0x0-0x9ffff could not be reserved
[    1.580560] system 00:0f: iomem range 0xc0000-0xcffff has been reserved
[    1.580638] system 00:0f: iomem range 0xe0000-0xfffff could not be reserved
[    1.580718] system 00:0f: iomem range 0x100000-0xbf8fffff could not be reserved
[    1.580813] system 00:0f: iomem range 0xfed90000-0xffffffff could not be reserved
[    1.585552] pci 0000:01:01.0: BAR 6: address space collision on of device [0xfb9e0000-0xfb9fffff]
[    1.585719] pci 0000:00:01.0: PCI bridge, secondary bus 0000:0a
[    1.585795] pci 0000:00:01.0:   IO window: 0xe000-0xefff
[    1.585872] pci 0000:00:01.0:   MEM window: 0xfbe00000-0xfbefffff
[    1.585950] pci 0000:00:01.0:   PREFETCH window: disabled
[    1.586028] pci 0000:00:03.0: PCI bridge, secondary bus 0000:09
[    1.586104] pci 0000:00:03.0:   IO window: disabled
[    1.586180] pci 0000:00:03.0:   MEM window: 0xfbb00000-0xfbdfffff
[    1.586258] pci 0000:00:03.0:   PREFETCH window: disabled
[    1.586336] pci 0000:00:05.0: PCI bridge, secondary bus 0000:08
[    1.586411] pci 0000:00:05.0:   IO window: disabled
[    1.586487] pci 0000:00:05.0:   MEM window: disabled
[    1.586562] pci 0000:00:05.0:   PREFETCH window: disabled
[    1.586642] pci 0000:00:07.0: PCI bridge, secondary bus 0000:07
[    1.586718] pci 0000:00:07.0:   IO window: disabled
[    1.586794] pci 0000:00:07.0:   MEM window: disabled
[    1.586869] pci 0000:00:07.0:   PREFETCH window: disabled
[    1.586947] pci 0000:04:00.0: PCI bridge, secondary bus 0000:06
[    1.587023] pci 0000:04:00.0:   IO window: disabled
[    1.587099] pci 0000:04:00.0:   MEM window: disabled
[    1.587174] pci 0000:04:00.0:   PREFETCH window: disabled
[    1.587252] pci 0000:04:00.2: PCI bridge, secondary bus 0000:05
[    1.587328] pci 0000:04:00.2:   IO window: disabled
[    1.587403] pci 0000:04:00.2:   MEM window: disabled
[    1.587479] pci 0000:04:00.2:   PREFETCH window: disabled
[    1.587557] pci 0000:00:09.0: PCI bridge, secondary bus 0000:04
[    1.587632] pci 0000:00:09.0:   IO window: disabled
[    1.587708] pci 0000:00:09.0:   MEM window: disabled
[    1.587783] pci 0000:00:09.0:   PREFETCH window: disabled
[    1.587861] pci 0000:00:1c.0: PCI bridge, secondary bus 0000:03
[    1.587938] pci 0000:00:1c.0:   IO window: 0x1000-0x1fff
[    1.588016] pci 0000:00:1c.0:   MEM window: 0xc0000000-0xc01fffff
[    1.588094] pci 0000:00:1c.0:   PREFETCH window: 0x000000c0200000-0x000000c03fffff
[    1.588193] pci 0000:00:1c.4: PCI bridge, secondary bus 0000:02
[    1.588270] pci 0000:00:1c.4:   IO window: 0xd000-0xdfff
[    1.588348] pci 0000:00:1c.4:   MEM window: 0xfba00000-0xfbafffff
[    1.588426] pci 0000:00:1c.4:   PREFETCH window: 0x000000c0400000-0x000000c05fffff
[    1.588526] pci 0000:00:1e.0: PCI bridge, secondary bus 0000:01
[    1.588604] pci 0000:00:1e.0:   IO window: 0xc000-0xcfff
[    1.588681] pci 0000:00:1e.0:   MEM window: 0xfb900000-0xfb9fffff
[    1.588759] pci 0000:00:1e.0:   PREFETCH window: 0x000000f0000000-0x000000f7ffffff
[    1.588867] pci 0000:00:01.0: setting latency timer to 64
[    1.588874] pci 0000:00:03.0: setting latency timer to 64
[    1.588882] pci 0000:00:05.0: setting latency timer to 64
[    1.588890] pci 0000:00:07.0: setting latency timer to 64
[    1.588897] pci 0000:00:09.0: setting latency timer to 64
[    1.588905] pci 0000:04:00.0: setting latency timer to 64
[    1.588912] pci 0000:04:00.2: setting latency timer to 64
[    1.588919] pci 0000:00:1c.0: enabling device (0104 -> 0107)
[    1.589004] pci 0000:00:1c.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
[    1.589084] pci 0000:00:1c.0: setting latency timer to 64
[    1.589091] pci 0000:00:1c.4: PCI INT A -> GSI 17 (level, low) -> IRQ 17
[    1.589171] pci 0000:00:1c.4: setting latency timer to 64
[    1.589177] pci 0000:00:1e.0: setting latency timer to 64
[    1.589181] pci_bus 0000:00: resource 0 io:  [0x00-0xffff]
[    1.589184] pci_bus 0000:00: resource 1 mem: [0x000000-0xffffffffffffffff]
[    1.589186] pci_bus 0000:0a: resource 0 io:  [0xe000-0xefff]
[    1.589188] pci_bus 0000:0a: resource 1 mem: [0xfbe00000-0xfbefffff]
[    1.589191] pci_bus 0000:09: resource 1 mem: [0xfbb00000-0xfbdfffff]
[    1.589194] pci_bus 0000:03: resource 0 io:  [0x1000-0x1fff]
[    1.589196] pci_bus 0000:03: resource 1 mem: [0xc0000000-0xc01fffff]
[    1.589199] pci_bus 0000:03: resource 2 pref mem [0xc0200000-0xc03fffff]
[    1.589201] pci_bus 0000:02: resource 0 io:  [0xd000-0xdfff]
[    1.589203] pci_bus 0000:02: resource 1 mem: [0xfba00000-0xfbafffff]
[    1.589205] pci_bus 0000:02: resource 2 pref mem [0xc0400000-0xc05fffff]
[    1.589208] pci_bus 0000:01: resource 0 io:  [0xc000-0xcfff]
[    1.589210] pci_bus 0000:01: resource 1 mem: [0xfb900000-0xfb9fffff]
[    1.589212] pci_bus 0000:01: resource 2 pref mem [0xf0000000-0xf7ffffff]
[    1.589214] pci_bus 0000:01: resource 3 io:  [0x00-0xffff]
[    1.589216] pci_bus 0000:01: resource 4 mem: [0x000000-0xffffffffffffffff]
[    1.589280] NET: Registered protocol family 2
[    1.589751] IP route cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    1.591358] TCP established hash table entries: 524288 (order: 11, 8388608 bytes)
[    1.593348] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[    1.593647] TCP: Hash tables configured (established 524288 bind 65536)
[    1.593725] TCP reno registered
[    1.594006] NET: Registered protocol family 1
[    1.594323] RPC: Registered udp transport module.
[    1.594396] RPC: Registered tcp transport module.
[    1.594470] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.594757] pci 0000:01:01.0: Boot video device
[    1.594816] Trying to unpack rootfs image as initramfs...
[    1.715417] Freeing initrd memory: 4591k freed
[    1.719582] VFS: Disk quotas dquot_6.5.2
[    1.719678] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    1.720206] msgmni has been set to 32768
[    1.720590] alg: No test for stdrng (krng)
[    1.720694] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
[    1.720790] io scheduler noop registered
[    1.720862] io scheduler anticipatory registered
[    1.720935] io scheduler deadline registered
[    1.721029] io scheduler cfq registered (default)
[    1.721295] pcieport 0000:00:01.0: irq 72 for MSI/MSI-X
[    1.721303] pcieport 0000:00:01.0: setting latency timer to 64
[    1.721405] pcieport 0000:00:03.0: irq 73 for MSI/MSI-X
[    1.721411] pcieport 0000:00:03.0: setting latency timer to 64
[    1.721511] pcieport 0000:00:05.0: irq 74 for MSI/MSI-X
[    1.721518] pcieport 0000:00:05.0: setting latency timer to 64
[    1.721617] pcieport 0000:00:07.0: irq 75 for MSI/MSI-X
[    1.721624] pcieport 0000:00:07.0: setting latency timer to 64
[    1.721722] pcieport 0000:00:09.0: irq 76 for MSI/MSI-X
[    1.721729] pcieport 0000:00:09.0: setting latency timer to 64
[    1.721827] pcieport 0000:00:1c.0: irq 77 for MSI/MSI-X
[    1.721835] pcieport 0000:00:1c.0: setting latency timer to 64
[    1.721944] pcieport 0000:00:1c.4: irq 78 for MSI/MSI-X
[    1.721952] pcieport 0000:00:1c.4: setting latency timer to 64
[    1.738711] Real Time Clock Driver v1.12b
[    1.738889] Linux agpgart interface v0.103
[    1.738962] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.739132] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[    1.739328] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[    1.739771] 00:06: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[    1.740047] 00:07: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[    1.740378] Floppy drive(s): fd0 is 1.44M
[    1.758132] FDC 0 is a post-1991 82077
[    1.760145] brd: module loaded
[    1.760670] loop: module loaded
[    1.760740] HP CISS Driver (v 3.6.20)
[    1.760984] Adaptec aacraid driver 1.1-5[2461]-ms
[    1.761091] aacraid 0000:09:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    1.761172] aacraid 0000:09:00.0: setting latency timer to 64
[    1.826573] IRQ 16/aacraid: IRQF_DISABLED is not guaranteed on shared IRQs
[    2.033946] AAC0: kernel 5.2-0[17899] Apr 14 2010
[    2.034025] AAC0: monitor 5.2-0[17899]
[    2.034096] AAC0: bios 5.2-0[17899]
[    2.034168] AAC0: serial 9D511144775
[    2.034238] AAC0: Non-DASD support enabled.
[    2.034310] AAC0: 64bit support enabled.
[    2.034382] AAC0: 64 Bit DAC enabled
[    2.047360] scsi0 : aacraid
[    2.047643] scsi 0:0:0:0: Direct-Access     Adaptec  Vol1             V1.0 PQ: 0 ANSI: 2
[    2.048018] scsi 0:0:1:0: Direct-Access     Adaptec  Raid6            V1.0 PQ: 0 ANSI: 2
[    2.059436] scsi 0:1:8:0: Direct-Access              ST3250310NS      SN06 PQ: 1 ANSI: 5
[    2.059816] scsi 0:1:9:0: Direct-Access              ST3250310NS      SN06 PQ: 1 ANSI: 5
[    2.060179] scsi 0:1:10:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.060547] scsi 0:1:11:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.060920] scsi 0:1:12:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.061285] scsi 0:1:13:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.061646] scsi 0:1:14:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.062017] scsi 0:1:15:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.062383] scsi 0:1:16:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.062745] scsi 0:1:17:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.063116] scsi 0:1:18:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.063481] scsi 0:1:19:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.063847] scsi 0:1:20:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.064218] scsi 0:1:21:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.064591] scsi 0:1:22:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.064959] scsi 0:1:23:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.065329] scsi 0:1:24:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.065702] scsi 0:1:25:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.066071] scsi 0:1:26:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.066437] scsi 0:1:27:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.066807] scsi 0:1:28:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.067183] scsi 0:1:29:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.067556] scsi 0:1:30:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.067933] scsi 0:1:31:0: Direct-Access     Hitachi  HUA722020ALA330  JKAO PQ: 1 ANSI: 5
[    2.098990] scsi 0:3:0:0: Enclosure         LSILOGIC SASX36 A.1       7015 PQ: 0 ANSI: 3
[    2.115181] megaraid cmm: 2.20.2.7 (Release Date: Sun Jul 16 00:01:03 EST 2006)
[    2.115312] megaraid: 2.20.5.1 (Release Date: Thu Nov 16 15:32:35 EST 2006)
[    2.115404] megasas: 00.00.04.01 Thu July 24 11:41:51 PST 2008
[    2.115499] GDT-HA: Storage RAID Controller Driver. Version: 3.05
[    2.115589] 3ware Storage Controller device driver for Linux v1.26.02.002.
[    2.115678] 3ware 9000 Storage Controller device driver for Linux v2.26.02.012.
[    2.115788] st: Version 20081215, fixed bufsize 32768, s/g segs 256
[    2.116054] sd 0:0:1:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[    2.116058] sd 0:0:0:0: [sda] 488017920 512-byte logical blocks: (249 GB/232 GiB)
[    2.116075] ata_piix 0000:00:1f.2: version 2.13
[    2.116078] sd 0:0:0:0: [sda] Write Protect is off
[    2.116080] sd 0:0:0:0: [sda] Mode Sense: 06 00 10 00
[    2.116092] ata_piix 0000:00:1f.2: PCI INT B -> GSI 19 (level, low) -> IRQ 19
[    2.116096] ata_piix 0000:00:1f.2: MAP [ P0 P2 P1 P3 ]
[    2.116108] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, supports DPO and FUA
[    2.116137] ata_piix 0000:00:1f.2: setting latency timer to 64
[    2.116194] scsi1 : ata_piix
[    2.116252] scsi2 : ata_piix
[    2.118008] ata1: SATA max UDMA/133 cmd 0xbc00 ctl 0xb880 bmdma 0xb400 irq 19
[    2.118016] ata2: SATA max UDMA/133 cmd 0xb800 ctl 0xb480 bmdma 0xb408 irq 19
[    2.118040] ata_piix 0000:00:1f.5: PCI INT B -> GSI 19 (level, low) -> IRQ 19
[    2.118045] ata_piix 0000:00:1f.5: MAP [ P0 -- P1 -- ]
[    2.118091] ata_piix 0000:00:1f.5: setting latency timer to 64
[    2.118130] scsi3 : ata_piix
[    2.118187] scsi4 : ata_piix
[    2.119846] ata3: SATA max UDMA/133 cmd 0xac00 ctl 0xa880 bmdma 0xa400 irq 19
[    2.119851] ata4: SATA max UDMA/133 cmd 0xa800 ctl 0xa480 bmdma 0xa408 irq 19
[    2.119965] Fusion MPT base driver 3.04.12
[    2.119966] Copyright (c) 1999-2008 LSI Corporation
[    2.119973] Fusion MPT SPI Host driver 3.04.12
[    2.119987] Fusion MPT SAS Host driver 3.04.12
[    2.120052] PNP: PS/2 Controller [PNP0303:PS2K,PNP0f03:PS2M] at 0x60,0x64 irq 1,12
[    2.121561]  sda:
[    2.122348] serio: i8042 KBD port at 0x60,0x64 irq 1
[    2.122353] serio: i8042 AUX port at 0x60,0x64 irq 12
[    2.122437] mice: PS/2 mouse device common for all mice
[    2.122469]  sda1 sda2
[    2.124892] sd 0:0:1:0: [sdb] 74113331200 512-byte logical blocks: (37.9 TB/34.5 TiB)
[    2.124895] md: raid0 personality registered for level 0
[    2.124897] md: raid1 personality registered for level 1
[    2.124900] md: raid10 personality registered for level 10
[    2.124901] md: raid6 personality registered for level 6
[    2.124903] md: raid5 personality registered for level 5
[    2.124904] md: raid4 personality registered for level 4
[    2.124906] md: multipath personality registered for level -4
[    2.124990] sd 0:0:0:0: [sda] Attached SCSI removable disk
[    2.125594] sd 0:0:1:0: [sdb] Write Protect is off
[    2.125673] sd 0:0:1:0: [sdb] Mode Sense: 06 00 10 00
[    2.125697] sd 0:0:1:0: [sdb] Write cache: disabled, read cache: enabled, supports DPO and FUA
[    2.125857] device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel@redhat.com
[    2.126030] EDAC MC: Ver: 2.1.0 Feb 23 2011
[    2.126257] cpuidle: using governor ladder
[    2.126443] TCP cubic registered
[    2.126532] NET: Registered protocol family 17
[    2.127508] sd 0:0:1:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[    2.127649]  sdb: unknown partition table
[    2.127898] sd 0:0:1:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[    2.128038] sd 0:0:1:0: [sdb] Attached SCSI removable disk
[    2.140476] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0
[    2.393896] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input1
[    2.449980] ata4: SATA link down (SStatus 0 SControl 300)
[    2.460683] ata3: SATA link down (SStatus 0 SControl 300)
[    2.765421] ata2.00: SATA link down (SStatus 0 SControl 300)
[    2.765510] ata2.01: SATA link down (SStatus 0 SControl 300)
[    2.776151] ata1.00: SATA link down (SStatus 0 SControl 300)
[    2.776239] ata1.01: SATA link down (SStatus 0 SControl 300)
[    2.776365] Freeing unused kernel memory: 516k freed
[    2.776556] Write protecting the kernel read-only data: 5440k
[    3.127359] Intel(R) Gigabit Ethernet Network Driver - version 1.3.16-k2
[    3.127457] Copyright (c) 2007-2009 Intel Corporation.
[    3.127573] igb 0000:0a:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    3.127661] igb 0000:0a:00.0: setting latency timer to 64
[    3.127925] igb 0000:0a:00.0: irq 79 for MSI/MSI-X
[    3.127928] igb 0000:0a:00.0: irq 80 for MSI/MSI-X
[    3.127931] igb 0000:0a:00.0: irq 81 for MSI/MSI-X
[    3.127934] igb 0000:0a:00.0: irq 82 for MSI/MSI-X
[    3.127937] igb 0000:0a:00.0: irq 83 for MSI/MSI-X
[    3.127940] igb 0000:0a:00.0: irq 84 for MSI/MSI-X
[    3.127943] igb 0000:0a:00.0: irq 85 for MSI/MSI-X
[    3.127946] igb 0000:0a:00.0: irq 86 for MSI/MSI-X
[    3.127948] igb 0000:0a:00.0: irq 87 for MSI/MSI-X
[    3.318644] igb 0000:0a:00.0: Intel(R) Gigabit Ethernet Network Connection
[    3.318729] igb 0000:0a:00.0: eth0: (PCIe:2.5Gb/s:Width x4) 00:30:48:cf:ff:84
[    3.318883] igb 0000:0a:00.0: eth0: PBA No: 0010ff-0ff
[    3.318958] igb 0000:0a:00.0: Using MSI-X interrupts. 4 rx queue(s), 4 tx queue(s)
[    3.319081] igb 0000:0a:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[    3.319170] igb 0000:0a:00.1: setting latency timer to 64
[    3.319431] igb 0000:0a:00.1: irq 88 for MSI/MSI-X
[    3.319434] igb 0000:0a:00.1: irq 89 for MSI/MSI-X
[    3.319437] igb 0000:0a:00.1: irq 90 for MSI/MSI-X
[    3.319439] igb 0000:0a:00.1: irq 91 for MSI/MSI-X
[    3.319442] igb 0000:0a:00.1: irq 92 for MSI/MSI-X
[    3.319444] igb 0000:0a:00.1: irq 93 for MSI/MSI-X
[    3.319447] igb 0000:0a:00.1: irq 94 for MSI/MSI-X
[    3.319449] igb 0000:0a:00.1: irq 95 for MSI/MSI-X
[    3.319452] igb 0000:0a:00.1: irq 96 for MSI/MSI-X
[    3.482177] usbcore: registered new interface driver usbfs
[    3.482289] usbcore: registered new interface driver hub
[    3.482389] usbcore: registered new device driver usb
[    3.484054] uhci_hcd: USB Universal Host Controller Interface driver
[    3.484192] uhci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    3.484276] uhci_hcd 0000:00:1a.0: setting latency timer to 64
[    3.484284] uhci_hcd 0000:00:1a.0: UHCI Host Controller
[    3.484378] uhci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 1
[    3.484497] uhci_hcd 0000:00:1a.0: irq 16, io base 0x00009400
[    3.484701] usb usb1: configuration #1 chosen from 1 choice
[    3.484798] hub 1-0:1.0: USB hub found
[    3.484874] hub 1-0:1.0: 2 ports detected
[    3.485013] uhci_hcd 0000:00:1a.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
[    3.485097] uhci_hcd 0000:00:1a.1: setting latency timer to 64
[    3.485099] uhci_hcd 0000:00:1a.1: UHCI Host Controller
[    3.485179] uhci_hcd 0000:00:1a.1: new USB bus registered, assigned bus number 2
[    3.485303] uhci_hcd 0000:00:1a.1: irq 21, io base 0x00009480
[    3.485453] usb usb2: configuration #1 chosen from 1 choice
[    3.485549] hub 2-0:1.0: USB hub found
[    3.485623] hub 2-0:1.0: 2 ports detected
[    3.485752] uhci_hcd 0000:00:1a.2: PCI INT D -> GSI 19 (level, low) -> IRQ 19
[    3.485834] uhci_hcd 0000:00:1a.2: setting latency timer to 64
[    3.485837] uhci_hcd 0000:00:1a.2: UHCI Host Controller
[    3.485916] uhci_hcd 0000:00:1a.2: new USB bus registered, assigned bus number 3
[    3.486032] uhci_hcd 0000:00:1a.2: irq 19, io base 0x00009800
[    3.486126] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    3.486182] usb usb3: configuration #1 chosen from 1 choice
[    3.486205] hub 3-0:1.0: USB hub found
[    3.486210] hub 3-0:1.0: 2 ports detected
[    3.486267] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[    3.486273] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[    3.486276] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[    3.486282] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 4
[    3.486317] uhci_hcd 0000:00:1d.0: irq 23, io base 0x00009880
[    3.486395] usb usb4: configuration #1 chosen from 1 choice
[    3.486417] hub 4-0:1.0: USB hub found
[    3.486422] hub 4-0:1.0: 2 ports detected
[    3.486477] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 19 (level, low) -> IRQ 19
[    3.486482] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[    3.486485] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[    3.486493] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 5
[    3.486523] uhci_hcd 0000:00:1d.1: irq 19, io base 0x00009c00
[    3.486596] usb usb5: configuration #1 chosen from 1 choice
[    3.486619] hub 5-0:1.0: USB hub found
[    3.486623] hub 5-0:1.0: 2 ports detected
[    3.486684] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[    3.486690] uhci_hcd 0000:00:1d.2: setting latency timer to 64
[    3.486693] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[    3.486699] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 6
[    3.486727] uhci_hcd 0000:00:1d.2: irq 18, io base 0x0000a000
[    3.486805] usb usb6: configuration #1 chosen from 1 choice
[    3.486827] hub 6-0:1.0: USB hub found
[    3.486832] hub 6-0:1.0: 2 ports detected
[    3.488036] Warning! ehci_hcd should always be loaded before uhci_hcd and ohci_hcd, not after
[    3.488168] ehci_hcd 0000:00:1a.7: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[    3.488281] ehci_hcd 0000:00:1a.7: setting latency timer to 64
[    3.488284] ehci_hcd 0000:00:1a.7: EHCI Host Controller
[    3.488370] ehci_hcd 0000:00:1a.7: new USB bus registered, assigned bus number 7
[    3.488505] ehci_hcd 0000:00:1a.7: debug port 1
[    3.492452] ehci_hcd 0000:00:1a.7: cache line size of 32 is not supported
[    3.492461] ehci_hcd 0000:00:1a.7: irq 18, io mem 0xfb8fa000
[    3.511843] ehci_hcd 0000:00:1a.7: USB 2.0 started, EHCI 1.00
[    3.512054] usb usb7: configuration #1 chosen from 1 choice
[    3.512158] hub 7-0:1.0: USB hub found
[    3.512235] hub 7-0:1.0: 6 ports detected
[    3.512386] ehci_hcd 0000:00:1d.7: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[    3.512480] ehci_hcd 0000:00:1d.7: setting latency timer to 64
[    3.512483] ehci_hcd 0000:00:1d.7: EHCI Host Controller
[    3.512563] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 8
[    3.512688] ehci_hcd 0000:00:1d.7: debug port 1
[    3.514455] igb 0000:0a:00.1: Intel(R) Gigabit Ethernet Network Connection
[    3.514541] igb 0000:0a:00.1: eth1: (PCIe:2.5Gb/s:Width x4) 00:30:48:cf:ff:85
[    3.514701] igb 0000:0a:00.1: eth1: PBA No: 0010ff-0ff
[    3.514781] igb 0000:0a:00.1: Using MSI-X interrupts. 4 rx queue(s), 4 tx queue(s)
[    3.516637] ehci_hcd 0000:00:1d.7: cache line size of 32 is not supported
[    3.516645] ehci_hcd 0000:00:1d.7: irq 23, io mem 0xfb8fc000
[    3.535820] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[    3.535983] usb usb8: configuration #1 chosen from 1 choice
[    3.536082] hub 8-0:1.0: USB hub found
[    3.536159] hub 8-0:1.0: 6 ports detected
[    3.824714] usb 7-5: new high speed USB device using ehci_hcd and address 2
[    3.958182] usb 7-5: configuration #1 chosen from 1 choice
[    4.322693] usb 4-2: new low speed USB device using uhci_hcd and address 2
[    4.493529] usb 4-2: configuration #1 chosen from 1 choice
[    5.231673] input: Peppercon AG Multidevice as /devices/pci0000:00/0000:00:1a.7/usb7/7-5/7-5:1.0/input/input2
[    5.231858] generic-usb 0003:14DD:0002.0001: input: USB HID v1.01 Mouse [Peppercon AG Multidevice] on usb-0000:00:1a.7-5/input0
[    5.233134] input: Peppercon AG Multidevice as /devices/pci0000:00/0000:00:1a.7/usb7/7-5/7-5:1.1/input/input3
[    5.233267] generic-usb 0003:14DD:0002.0002: input: USB HID v1.01 Keyboard [Peppercon AG Multidevice] on usb-0000:00:1a.7-5/input1
[    5.233387] usbcore: registered new interface driver usbhid
[    5.233463] usbhid: v2.6:USB HID core driver
[    5.531513] EXT3-fs: INFO: recovery required on readonly filesystem.
[    5.531591] EXT3-fs: write access will be enabled during recovery.
[    5.906543] kjournald starting.  Commit interval 5 seconds
[    5.906553] EXT3-fs: dm-0: orphan cleanup on readonly fs
[    5.911646] ext3_orphan_cleanup: deleting unreferenced inode 36809
[    5.923295] EXT3-fs: dm-0: 1 orphan inode deleted
[    5.923375] EXT3-fs: recovery complete.
[    5.930764] EXT3-fs: mounted filesystem with ordered data mode.
[    6.720152] udevd version 125 started
[    7.003153] ACPI: SSDT 00000000bf79e1f0 00FAC (v01 DpgPmm  P001Ist 00000011 INTL 20051117)
[    7.004045] ACPI: SSDT 00000000bf79f1a0 00659 (v01  PmRef  P001Cst 00003001 INTL 20051117)
[    7.007022] input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input4
[    7.007126] ACPI: Power Button [PWRB]
[    7.007209] Monitor-Mwait will be used to enter C-3 state
[    7.007441] Monitor-Mwait will be used to enter C-3 state
[    7.007541] processor LNXCPU:00: registered as cooling_device0
[    7.007677] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input5
[    7.007774] ACPI: Power Button [PWRF]
[    7.012236] processor LNXCPU:01: registered as cooling_device1
[    7.013692] processor LNXCPU:02: registered as cooling_device2
[    7.015148] processor LNXCPU:03: registered as cooling_device3
[    7.016777] processor LNXCPU:04: registered as cooling_device4
[    7.033370] processor LNXCPU:05: registered as cooling_device5
[    7.035002] processor LNXCPU:06: registered as cooling_device6
[    7.045118] processor LNXCPU:07: registered as cooling_device7
[    7.932691] i801_smbus 0000:00:1f.3: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[   10.151054] Adding 41943032k swap on /dev/mapper/vgroot-swap.  Priority:-1 extents:1 across:41943032k 
[   10.162387] EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
[   10.162626] EXT3 FS on dm-0, internal journal
[   25.605369] fuse init (API version 7.13)
[   25.787164] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended
[   25.824638] kjournald starting.  Commit interval 5 seconds
[   25.824935] EXT3 FS on dm-2, internal journal
[   25.825065] EXT3-fs: mounted filesystem with ordered data mode.
[   25.826775] kjournald starting.  Commit interval 5 seconds
[   25.826941] EXT3 FS on dm-3, internal journal
[   25.827117] EXT3-fs: mounted filesystem with ordered data mode.
[   25.828785] kjournald starting.  Commit interval 5 seconds
[   25.828894] EXT3 FS on dm-4, internal journal
[   25.828897] EXT3-fs: mounted filesystem with ordered data mode.
[   25.854908] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
[   25.860131] SGI XFS Quota Management subsystem
[   25.878264] XFS mounting filesystem dm-6
[   26.014187] Starting XFS recovery on filesystem: dm-6 (logdev: internal)
[   26.168204] Ending XFS recovery on filesystem: dm-6 (logdev: internal)
[   26.185153] XFS mounting filesystem dm-5
[   26.338834] Starting XFS recovery on filesystem: dm-5 (logdev: internal)
[   26.606237] Ending XFS recovery on filesystem: dm-5 (logdev: internal)
[   26.607341] Filesystem "dm-8": Disabling barriers, not supported with external log device
[   26.630941] XFS mounting filesystem dm-8
[   26.787638] Starting XFS recovery on filesystem: dm-8 (logdev: /dev/vgroot/raid6-intern-log)
[   27.425554] Ending XFS recovery on filesystem: dm-8 (logdev: /dev/vgroot/raid6-intern-log)
[   29.169529] igb: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[   29.254818] ip_tables: (C) 2000-2006 Netfilter Core Team
[   29.266829] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[   29.267790] CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use
[   29.267885] nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or
[   29.267981] sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
[   39.988554] igb: eth1 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[   50.330508] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).

[-- Attachment #3: kern.log.1.gz --]
[-- Type: application/x-gzip, Size: 14558 bytes --]

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
       [not found]                                   ` <alpine.DEB.2.00.1107051013500.16869@router.home>
@ 2011-07-05 17:20                                     ` Mel Gorman
  2011-07-06  4:16                                       ` Dave Chinner
  0 siblings, 1 reply; 27+ messages in thread
From: Mel Gorman @ 2011-07-05 17:20 UTC (permalink / raw)
  To: Christoph Lameter; +Cc: David Rientjes, eric.dumazet, Peter Kruse, linux-kernel

On Tue, Jul 05, 2011 at 10:18:44AM -0500, Christoph Lameter wrote:
> On Tue, 28 Jun 2011, Peter Kruse wrote:
> 
> > the server crashed again, I attach the dmesg and kern.log that
> > contain some call traces.  Could you have a look again?
> > This time the server runs 2.6.32.29.
> 
> These are messages about a hung task. I do not see any page allocation
> failures in this log anymore. Mel can you have a look. Could it be that
> something holds up reclaim?

This is a new issue to me and I see it's against 2.6.32.29 which
isn't even the latest stable 2.6.32 so I don't think I'll be able to
dedicate a lot of time to this.

If kswapd is stuck in a loop, it's possible that it's stuck trying to
shrink slab, failing and unable to free the associated pages. sysrq+m
might have given a hint but I also see some worrying things like this
while glancing through the traces;

Jun 28 09:01:14 beosrv1-t kernel: [3702691.182966] dsmc          R  running task        0 27835      1 0x00020000
Jun 28 09:01:14 beosrv1-t kernel: [3702691.183139]  ffff88006ad6b728 0000000000000082 ffffffff8100b92e ffff88006ad6b728
Jun 28 09:01:14 beosrv1-t kernel: [3702691.183423]  000000000000dd08 ffff88006ad6bfd8 00000000000115c0 00000000000115c0
Jun 28 09:01:14 beosrv1-t kernel: [3702691.183707]  0000000000000000 ffffffffa00ef883 ffff880a18d5b810 ffff88006eccc770
Jun 28 09:01:14 beosrv1-t kernel: [3702691.183990] Call Trace:
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184060]  [<ffffffff8100b92e>] ? apic_timer_interrupt+0xe/0x20
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184149]  [<ffffffffa00ef883>] ? xfs_reclaim_inode+0x0/0xef [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184237]  [<ffffffffa00f0370>] ? xfs_inode_ag_iterator+0x6f/0xaf [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184327]  [<ffffffffa00ef883>] ? xfs_reclaim_inode+0x0/0xef [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184406]  [<ffffffff81034ad5>] __cond_resched+0x25/0x31
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184483]  [<ffffffff813dd3d3>] ? _cond_resched+0x0/0x2f
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184560]  [<ffffffff813dd3f7>] _cond_resched+0x24/0x2f
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184637]  [<ffffffff810779cb>] shrink_slab+0x10d/0x154
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184713]  [<ffffffff81078694>] try_to_free_pages+0x221/0x31c
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184791]  [<ffffffff810757de>] ? isolate_pages_global+0x0/0x1f0
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184869]  [<ffffffff8107260d>] __alloc_pages_nodemask+0x3fd/0x600
Jun 28 09:01:14 beosrv1-t kernel: [3702691.184948]  [<ffffffff81094d83>] kmem_getpages+0x5c/0x127
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185024]  [<ffffffff81094f6d>] fallback_alloc+0x11f/0x195
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185102]  [<ffffffff8109510c>] ____cache_alloc_node+0x129/0x138
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185180]  [<ffffffff81095ad5>] kmem_cache_alloc+0xd1/0xfe
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185268]  [<ffffffffa00e5aab>] kmem_zone_alloc+0x67/0xaf [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185358]  [<ffffffffa00cbdb1>] xfs_inode_alloc+0x24/0xcd [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185448]  [<ffffffffa00c0473>] ? xfs_dir_lookup+0xfc/0x153 [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185539]  [<ffffffffa00cc10c>] xfs_iget+0x2b2/0x472 [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185628]  [<ffffffffa00e3b1a>] xfs_lookup+0x7d/0xae [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185715]  [<ffffffffa00ebf43>] xfs_vn_lookup+0x3f/0x7e [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185793]  [<ffffffff810a2d29>] do_lookup+0xd5/0x1b9
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185869]  [<ffffffff810a4f35>] __link_path_walk+0x92e/0xdea
Jun 28 09:01:14 beosrv1-t kernel: [3702691.185946]  [<ffffffff810a2cb7>] ? do_lookup+0x63/0x1b9
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186024]  [<ffffffff810a5639>] path_walk+0x69/0xd4
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186100]  [<ffffffff810a5783>] do_path_lookup+0x29/0x51
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186176]  [<ffffffff810a61ab>] user_path_at+0x52/0x93
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186261]  [<ffffffffa00a4cff>] ? posix_acl_access_exists+0x2e/0x38 [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186351]  [<ffffffffa00f0988>] ? xfs_vn_listxattr+0xbd/0x100 [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186430]  [<ffffffff810a61bd>] ? user_path_at+0x64/0x93
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186506]  [<ffffffff8109e40e>] vfs_fstatat+0x35/0x62
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186592]  [<ffffffffa00f073c>] ? xfs_xattr_put_listent_sizes+0x0/0x30 [xfs]
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186688]  [<ffffffff8109e454>] vfs_lstat+0x19/0x1b
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186765]  [<ffffffff8102afbb>] sys32_lstat64+0x1a/0x34
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186841]  [<ffffffff810a2b18>] ? path_put+0x2c/0x30
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186917]  [<ffffffff810b3594>] ? sys_llistxattr+0x4d/0x5c
Jun 28 09:01:14 beosrv1-t kernel: [3702691.186995]  [<ffffffff8102a0d3>] ia32_sysret+0x0/0x5

That looks like XFS could be recursing into itself but maybe it copes
with that and bails - I'm not familiar enough with XFS to know if it
copes with this properly.

There are also patches that should be in 2.6.32.29 like [e52af507:
xfs: Non-blocking inode locking in IO completion] which talks
about deadlocks during IO completion but the kernel name is
2.6.32.29-ql-server-20. Does that include this patch or is it some
other fork?

What seems more plausible is 2.6.32.29 is missing patches like this
[081003ff: xfs: properly account for reclaimed inodes] which sounds
like a very similar problem to what is happening here. There is a good
chance this problem is already fixed but wasn't backported to 2.6.32.x
unfortunately.

-- 
Mel Gorman
SUSE Labs

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-05 17:20                                     ` Mel Gorman
@ 2011-07-06  4:16                                       ` Dave Chinner
  2011-07-06  6:50                                         ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Dave Chinner @ 2011-07-06  4:16 UTC (permalink / raw)
  To: Mel Gorman
  Cc: Christoph Lameter, David Rientjes, eric.dumazet, Peter Kruse,
	linux-kernel

On Tue, Jul 05, 2011 at 06:20:43PM +0100, Mel Gorman wrote:
> There are also patches that should be in 2.6.32.29 like [e52af507:
> xfs: Non-blocking inode locking in IO completion] which talks
> about deadlocks during IO completion but the kernel name is
> 2.6.32.29-ql-server-20. Does that include this patch or is it some
> other fork?
> 
> What seems more plausible is 2.6.32.29 is missing patches like this
> [081003ff: xfs: properly account for reclaimed inodes] which sounds
> like a very similar problem to what is happening here. There is a good
> chance this problem is already fixed but wasn't backported to 2.6.32.x
> unfortunately.

Fixed in 2.6.32.42.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-06  4:16                                       ` Dave Chinner
@ 2011-07-06  6:50                                         ` Peter Kruse
  2011-07-06 14:31                                           ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-07-06  6:50 UTC (permalink / raw)
  To: Dave Chinner
  Cc: Mel Gorman, Christoph Lameter, David Rientjes, eric.dumazet,
	linux-kernel

Hi there,

thanks for looking into this!

On 07/05/2011 07:20 PM, Mel Gorman wrote:
> There are also patches that should be in 2.6.32.29 like [e52af507:
> xfs: Non-blocking inode locking in IO completion] which talks
> about deadlocks during IO completion but the kernel name is
> 2.6.32.29-ql-server-20. Does that include this patch or is it some
> other fork?

it's not really a fork, we basically give the kernel a name.

Ok then I think we will schedule a kernel update and if the
server then runs for more than 40 days we could say that
the problem is fixed.

all the best,

  Peter

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-06  6:50                                         ` Peter Kruse
@ 2011-07-06 14:31                                           ` Christoph Lameter
  2011-07-06 15:15                                             ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-07-06 14:31 UTC (permalink / raw)
  To: Peter Kruse
  Cc: Dave Chinner, Mel Gorman, David Rientjes, eric.dumazet, linux-kernel

On Wed, 6 Jul 2011, Peter Kruse wrote:

> Ok then I think we will schedule a kernel update and if the
> server then runs for more than 40 days we could say that
> the problem is fixed.

Note that this is *not* the original problem you reported. I do not see
page alloc failures in your latest logs.


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-06 14:31                                           ` Christoph Lameter
@ 2011-07-06 15:15                                             ` Peter Kruse
  2011-07-06 15:30                                               ` Christoph Lameter
  0 siblings, 1 reply; 27+ messages in thread
From: Peter Kruse @ 2011-07-06 15:15 UTC (permalink / raw)
  To: Christoph Lameter
  Cc: Dave Chinner, Mel Gorman, David Rientjes, eric.dumazet, linux-kernel

Hi,

On 07/06/2011 04:31 PM, Christoph Lameter wrote:
> On Wed, 6 Jul 2011, Peter Kruse wrote:
> 
>> Ok then I think we will schedule a kernel update and if the
>> server then runs for more than 40 days we could say that
>> the problem is fixed.
> 
> Note that this is *not* the original problem you reported. I do not see
> page alloc failures in your latest logs.
> 

yes, I see.  Maybe originally there were two problems of which one is
now solved?

Regards,

  Peter

^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-06 15:15                                             ` Peter Kruse
@ 2011-07-06 15:30                                               ` Christoph Lameter
  2011-11-24 10:53                                                 ` Peter Kruse
  0 siblings, 1 reply; 27+ messages in thread
From: Christoph Lameter @ 2011-07-06 15:30 UTC (permalink / raw)
  To: Peter Kruse
  Cc: Dave Chinner, Mel Gorman, David Rientjes, eric.dumazet, linux-kernel

On Wed, 6 Jul 2011, Peter Kruse wrote:

> > Note that this is *not* the original problem you reported. I do not see
> > page alloc failures in your latest logs.
> >
>
> yes, I see.  Maybe originally there were two problems of which one is
> now solved?

That could be the case. Please run the latest 2.6.32 as requested by Mel.


^ permalink raw reply	[flat|nested] 27+ messages in thread

* Re: I have a blaze of 353 page allocation failures, all alike
  2011-07-06 15:30                                               ` Christoph Lameter
@ 2011-11-24 10:53                                                 ` Peter Kruse
  0 siblings, 0 replies; 27+ messages in thread
From: Peter Kruse @ 2011-11-24 10:53 UTC (permalink / raw)
  To: Christoph Lameter
  Cc: Dave Chinner, Mel Gorman, David Rientjes, eric.dumazet, linux-kernel

Hello all,

On 07/06/2011 05:30 PM, Christoph Lameter wrote:
> On Wed, 6 Jul 2011, Peter Kruse wrote:
> 
>>> Note that this is *not* the original problem you reported. I do not see
>>> page alloc failures in your latest logs.
>>>
>>
>> yes, I see.  Maybe originally there were two problems of which one is
>> now solved?
> 
> That could be the case. Please run the latest 2.6.32 as requested by Mel.
> 

the problem seems to be solved indeed.  The server now has an uptime
of 50 days without any problems where it crashed in the past
after at most 42 days.

Thank you all,

  Peter

^ permalink raw reply	[flat|nested] 27+ messages in thread

end of thread, other threads:[~2011-11-24 11:03 UTC | newest]

Thread overview: 27+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2011-02-10 15:03 I have a blaze of 353 page allocation failures, all alike Peter Kruse
2011-02-14 16:49 ` Christoph Lameter
2011-02-15  7:44   ` Peter Kruse
2011-02-15 17:30     ` Christoph Lameter
2011-02-16 12:22       ` Peter Kruse
2011-02-16 15:59         ` Christoph Lameter
2011-02-16 16:03           ` Peter Kruse
2011-02-16 16:14             ` Christoph Lameter
2011-02-17  7:31               ` Peter Kruse
2011-02-17 17:03                 ` Christoph Lameter
2011-02-18 12:30                   ` Peter Kruse
2011-02-24 12:01                     ` Peter Kruse
2011-04-12 15:01                       ` Peter Kruse
2011-04-12 18:08                         ` Christoph Lameter
2011-04-13  1:34                           ` David Rientjes
2011-04-13  7:13                             ` Peter Kruse
2011-04-13 16:17                               ` Christoph Lameter
2011-05-19 11:56                                 ` Peter Kruse
2011-05-19 16:00                                   ` Christoph Lameter
2011-05-23  6:34                                     ` Peter Kruse
     [not found]                                 ` <4E09BEA1.1080501@q-leap.de>
     [not found]                                   ` <alpine.DEB.2.00.1107051013500.16869@router.home>
2011-07-05 17:20                                     ` Mel Gorman
2011-07-06  4:16                                       ` Dave Chinner
2011-07-06  6:50                                         ` Peter Kruse
2011-07-06 14:31                                           ` Christoph Lameter
2011-07-06 15:15                                             ` Peter Kruse
2011-07-06 15:30                                               ` Christoph Lameter
2011-11-24 10:53                                                 ` Peter Kruse

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).