Return-path: Received: from cpsmtpm-eml110.kpnxchange.com ([195.121.3.14]:52931 "EHLO CPSMTPM-EML110.kpnxchange.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751294AbZIPOgS (ORCPT ); Wed, 16 Sep 2009 10:36:18 -0400 From: Frans Pop To: Mel Gorman Subject: Re: iwlagn: order 2 page allocation failures Date: Wed, 16 Sep 2009 16:36:16 +0200 Cc: Larry Finger , "John W. Linville" , Pekka Enberg , linux-kernel@vger.kernel.org, linux-wireless@vger.kernel.org, ipw3945-devel@lists.sourceforge.net, Andrew Morton , cl@linux-foundation.org, Assaf Krauss , Johannes Berg , Mohamed Abbas References: <200909060941.01810.elendil@planet.nl> <20090909165545.GK24614@csn.ul.ie> <200909091919.16461.elendil@planet.nl> In-Reply-To: <200909091919.16461.elendil@planet.nl> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-15" Message-Id: <200909161636.20590.elendil@planet.nl> Sender: linux-wireless-owner@vger.kernel.org List-ID: On Wednesday 09 September 2009, Frans Pop wrote: > On Wednesday 09 September 2009, you wrote: > > The problem with this theory is that the patches have been in since > > Nov 2008 but reports are only showing up now. Frans, how sure are you > > that this is a recent problem? Is it readily reproducible? > > The only thing I can say here is that I've never seen the issue before > (and thanks to logcheck I certainly would have). > The laptop is in constant use, but I rarely stress the memory like that. > Swap is almost always at 0. JFYI, it happened again yesterday. The first time it was swapper, here it's kcryptd. The top part of the trace is the same. kcryptd: page allocation failure. order:2, mode:0x4020 Pid: 1347, comm: kcryptd Not tainted 2.6.31-rc9 #16 Call Trace: [] __alloc_pages_nodemask+0x542/0x58a [] ? _spin_unlock+0x9/0xb [] ? __alloc_skb+0x3c/0x15b [] ? iwl_rx_allocate+0xac/0x208 [iwlcore] [] __get_free_pages+0x12/0x41 [] __kmalloc_track_caller+0x3b/0xec [] __alloc_skb+0x66/0x15b [] iwl_rx_allocate+0xac/0x208 [iwlcore] [] iwl_rx_replenish_now+0x16/0x23 [iwlcore] [] iwl_rx_handle+0x356/0x39a [iwlagn] [] ? scsi_io_completion+0x3a8/0x3d1 [scsi_mod] [] iwl_irq_tasklet_legacy+0x500/0x74f [iwlagn] [] ? scsi_finish_command+0xec/0xf5 [scsi_mod] [] tasklet_action+0x71/0xbc [] __do_softirq+0x9b/0x12c [] call_softirq+0x1c/0x28 [] do_softirq+0x34/0x72 [] irq_exit+0x3f/0x79 [] do_IRQ+0xa3/0xba [] ret_from_intr+0x0/0xa [] ? enc128+0x243/0x80b [aes_x86_64] [] ? aes_encrypt+0xd/0xf [aes_x86_64] [] ? crypto_cbc_encrypt+0x12c/0x18e [cbc] [] ? __alloc_pages_nodemask+0x12d/0x58a [] ? aes_encrypt+0x0/0xf [aes_x86_64] [] ? async_encrypt+0x38/0x3a [] ? mempool_alloc+0x5b/0x113 [] ? crypt_convert+0x1f9/0x278 [dm_crypt] [] ? kcryptd_crypt+0x423/0x449 [dm_crypt] [] ? kcryptd_crypt+0x0/0x449 [dm_crypt] [] ? worker_thread+0x132/0x1ca [] ? autoremove_wake_function+0x0/0x38 [] ? worker_thread+0x0/0x1ca [] ? kthread+0x8f/0x97 [] ? child_rip+0xa/0x20 [] ? kthread+0x0/0x97 [] ? child_rip+0x0/0x20 Mem-Info: DMA per-cpu: CPU 0: hi: 0, btch: 1 usd: 0 CPU 1: hi: 0, btch: 1 usd: 0 DMA32 per-cpu: CPU 0: hi: 186, btch: 31 usd: 172 CPU 1: hi: 186, btch: 31 usd: 163 Active_anon:278449 active_file:18846 inactive_anon:93192 inactive_file:18343 unevictable:407 dirty:0 writeback:7726 unstable:0 free:25175 slab:10409 mapped:34634 pagetables:4385 bounce:0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:2220kB inactive_anon:2464kB active_file:1084kB inactive_file:1608kB unevictable:0kB present:15336kB pages_scanned:0 all_unreclaimable? no lowmem_reserve[]: 0 1976 1976 1976 DMA32 free:92776kB min:5664kB low:7080kB high:8496kB active_anon:1111448kB inactive_anon:370432kB active_file:74300kB inactive_file:71764kB unevictable:1628kB present:2023748kB pages_scanned:32 all_unreclaimable? no lowmem_reserve[]: 0 0 0 0 DMA: 63*4kB 59*8kB 26*16kB 34*32kB 23*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB = 7924kB DMA32: 18882*4kB 2076*8kB 10*16kB 1*32kB 1*64kB 1*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 92776kB 82554 total pagecache pages 44961 pages in swap cache Swap cache stats: add 160004, delete 115046, find 2431510/2434120 Free swap = 1549576kB Total swap = 2097144kB 518064 pages RAM 10323 pages reserved 117029 pages shared 398165 pages non-shared iwlagn 0000:10:00.0: Can not allocate SKB buffers kcryptd: page allocation failure. order:2, mode:0x4020 Pid: 1347, comm: kcryptd Not tainted 2.6.31-rc9 #16 Call Trace: [] __alloc_pages_nodemask+0x542/0x58a [] ? _spin_unlock+0x9/0xb [] ? __alloc_skb+0x3c/0x15b [] ? iwl_rx_allocate+0xac/0x208 [iwlcore] [] __get_free_pages+0x12/0x41 [] __kmalloc_track_caller+0x3b/0xec [] __alloc_skb+0x66/0x15b [] iwl_rx_allocate+0xac/0x208 [iwlcore] [] iwl_rx_replenish_now+0x16/0x23 [iwlcore] [] iwl_rx_handle+0x381/0x39a [iwlagn] [] ? scsi_io_completion+0x3a8/0x3d1 [scsi_mod] [] iwl_irq_tasklet_legacy+0x500/0x74f [iwlagn] [] ? scsi_finish_command+0xec/0xf5 [scsi_mod] [] tasklet_action+0x71/0xbc [] __do_softirq+0x9b/0x12c [] call_softirq+0x1c/0x28 [] do_softirq+0x34/0x72 [] irq_exit+0x3f/0x79 [] do_IRQ+0xa3/0xba [] ret_from_intr+0x0/0xa [] ? enc128+0x243/0x80b [aes_x86_64] [] ? aes_encrypt+0xd/0xf [aes_x86_64] [] ? crypto_cbc_encrypt+0x12c/0x18e [cbc] [] ? __alloc_pages_nodemask+0x12d/0x58a [] ? aes_encrypt+0x0/0xf [aes_x86_64] [] ? async_encrypt+0x38/0x3a [] ? mempool_alloc+0x5b/0x113 [] ? crypt_convert+0x1f9/0x278 [dm_crypt] [] ? kcryptd_crypt+0x423/0x449 [dm_crypt] [] ? kcryptd_crypt+0x0/0x449 [dm_crypt] [] ? worker_thread+0x132/0x1ca [] ? autoremove_wake_function+0x0/0x38 [] ? worker_thread+0x0/0x1ca [] ? kthread+0x8f/0x97 [] ? child_rip+0xa/0x20 [] ? kthread+0x0/0x97 [] ? child_rip+0x0/0x20 Mem-Info: DMA per-cpu: CPU 0: hi: 0, btch: 1 usd: 0 CPU 1: hi: 0, btch: 1 usd: 0 DMA32 per-cpu: CPU 0: hi: 186, btch: 31 usd: 172 CPU 1: hi: 186, btch: 31 usd: 173 Active_anon:277951 active_file:18714 inactive_anon:93068 inactive_file:18252 unevictable:407 dirty:0 writeback:7726 unstable:0 free:25861 slab:10409 mapped:34634 pagetables:4385 bounce:0 DMA free:7924kB min:40kB low:48kB high:60kB active_anon:2220kB inactive_anon:2464kB active_file:1084kB inactive_file:1608kB unevictable:0kB present:15336kB pages_scanned:0 all_unreclaimable? no lowmem_reserve[]: 0 1976 1976 1976 DMA32 free:95520kB min:5664kB low:7080kB high:8496kB active_anon:1109584kB inactive_anon:369808kB active_file:73772kB inactive_file:71400kB unevictable:1628kB present:2023748kB pages_scanned:66 all_unreclaimable? no lowmem_reserve[]: 0 0 0 0 DMA: 63*4kB 59*8kB 26*16kB 34*32kB 23*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB = 7924kB DMA32: 19178*4kB 2285*8kB 3*16kB 1*32kB 1*64kB 1*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 95520kB 81717 total pagecache pages 44349 pages in swap cache Swap cache stats: add 160008, delete 115659, find 2431510/2434120 Free swap = 1549560kB Total swap = 2097144kB 518064 pages RAM 10323 pages reserved 117031 pages shared 398265 pages non-shared iwlagn 0000:10:00.0: Can not allocate SKB buffers