2012-09-09 21:32:31

by Pavel Machek

[permalink] [raw]
Subject: iwl3945: order 5 allocation during ifconfig up; vm problem?

Hi!

On 3.6.0-rc2+, I tried to turn on the wireless, but got

root@amd:~# ifconfig wlan0 10.0.0.6 up
SIOCSIFFLAGS: Cannot allocate memory
SIOCSIFFLAGS: Cannot allocate memory
root@amd:~#

It looks like it uses "a bit too big" allocations to allocate
firmware...? Order five allocation....

Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
network works. Is it VM problem that it failed to allocate memory when
it was freeable?

Pavel

iwl3945 0000:03:00.0: failed to allocate pci memory
iwl3945 0000:03:00.0: Could not read microcode: -12
firmware 0000:03:00.0: firmware_loading_store: vmap() failed
iwl3945 0000:03:00.0: iwlwifi-3945-2.ucode firmware file req failed:
-2
iwl3945 0000:03:00.0: Loaded firmware iwlwifi-3945-1.ucode, which is
deprecated. Please use API v2 instead.
iwl3945 0000:03:00.0: loaded firmware version 15.32.2.9
ifconfig: page allocation failure: order:5, mode:0x80d0
Pid: 21116, comm: ifconfig Tainted: G W 3.6.0-rc2+ #228
Call Trace:
[<c029ebf6>] warn_alloc_failed+0xb6/0x100
[<c02a0321>] __alloc_pages_nodemask+0x4c1/0x6e0
[<c020699c>] dma_generic_alloc_coherent+0x8c/0xc0
[<c05c4d59>] il3945_mac_start+0x1269/0x1280
[<c0206910>] ? dma_generic_free_coherent+0x30/0x30
[<c0800f64>] ? packet_notifier+0xc4/0x1a0
[<c088094c>] ieee80211_do_open+0x28c/0x840
[<c087f399>] ? ieee80211_check_concurrent_iface+0x19/0x190
[<c024c7ea>] ? raw_notifier_call_chain+0x1a/0x20
[<c0880f3b>] ieee80211_open+0x3b/0x80
[<c0769966>] __dev_open+0x96/0xf0
[<c08c73a5>] ? _raw_spin_unlock_bh+0x25/0x30
[<c076633d>] __dev_change_flags+0x7d/0x150
[<c076988e>] dev_change_flags+0x1e/0x60
[<c07d819d>] devinet_ioctl+0x69d/0x770
[<c076b026>] ? dev_ioctl+0x336/0x740
[<c07d959a>] inet_ioctl+0x9a/0xc0
[<c0756a33>] sock_ioctl+0x63/0x240
[<c07569d0>] ? sock_fasync+0x80/0x80
[<c02d91a3>] do_vfs_ioctl+0x83/0x570
[<c0223a50>] ? mm_fault_error+0x170/0x170
[<c024ba86>] ? up_read+0x16/0x30
[<c0223bcc>] ? do_page_fault+0x17c/0x3b0
[<c02d96c9>] sys_ioctl+0x39/0x70
[<c08c7c10>] sysenter_do_call+0x12/0x31
Mem-Info:
DMA per-cpu:
CPU 0: hi: 0, btch: 1 usd: 0
CPU 1: hi: 0, btch: 1 usd: 0
Normal per-cpu:
CPU 0: hi: 186, btch: 31 usd: 30
CPU 1: hi: 186, btch: 31 usd: 0
HighMem per-cpu:
CPU 0: hi: 186, btch: 31 usd: 0
CPU 1: hi: 186, btch: 31 usd: 0
active_anon:250783 inactive_anon:118977 isolated_anon:0
active_file:14686 inactive_file:13826 isolated_file:0
unevictable:0 dirty:3050 writeback:0 unstable:0
free:30113 slab_reclaimable:43820 slab_unreclaimable:34426
mapped:11898 shmem:19084 pagetables:3043 bounce:0
DMA free:1580kB min:64kB low:80kB high:96kB active_anon:0kB
inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:15788kB 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
lowmem_reserve[]: 0 864 2005 2005
Normal free:115348kB min:3728kB low:4660kB high:5592kB
active_anon:193616kB inactive_anon:192540kB active_file:19528kB
inactive_file:12916kB unevictable:0kB isolated(anon):0kB
isolated(file):0kB present:885072kB mlocked:0kB dirty:5388kB
writeback:0kB mapped:9212kB shmem:29100kB slab_reclaimable:175280kB
slab_unreclaimable:137704kB kernel_stack:6032kB pagetables:12172kB
unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
lowmem_reserve[]: 0 0 9125 9125
HighMem free:3524kB min:512kB low:1740kB high:2972kB
active_anon:809516kB inactive_anon:283368kB active_file:39216kB
inactive_file:42388kB unevictable:0kB isolated(anon):0kB
isolated(file):0kB present:1168080kB mlocked:0kB dirty:6812kB
writeback:0kB mapped:38380kB shmem:47236kB slab_reclaimable:0kB
slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB
bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 0 0
DMA: 1*4kB 1*8kB 0*16kB 1*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB
0*2048kB 0*4096kB = 1580kB
Normal: 4729*4kB 8354*8kB 1683*16kB 74*32kB 4*64kB 0*128kB 0*256kB
0*512kB 0*1024kB 0*2048kB 0*4096kB = 115300kB
HighMem: 537*4kB 118*8kB 27*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
0*1024kB 0*2048kB 0*4096kB = 3524kB
62305 total pagecache pages
14672 pages in swap cache
Swap cache stats: add 96156, delete 81484, find 3042279/3044117
Free swap = 480024kB
Total swap = 779148kB
521920 pages RAM
294610 pages HighMem
9083 pages reserved
244243 pages shared
450983 pages non-shared
iwl3945 0000:03:00.0: failed to allocate pci memory
iwl3945 0000:03:00.0: Could not read microcode: -12

--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html


2012-09-12 09:22:13

by Stanislaw Gruszka

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Tue, Sep 11, 2012 at 04:25:36PM -0700, Andrew Morton wrote:
> On Mon, 10 Sep 2012 13:11:13 +0200
> Pavel Machek <[email protected]> wrote:
>
> > On Sun 2012-09-09 15:40:55, David Rientjes wrote:
> > > On Sun, 9 Sep 2012, Pavel Machek wrote:
> > >
> > > > On 3.6.0-rc2+, I tried to turn on the wireless, but got
> > > >
> > > > root@amd:~# ifconfig wlan0 10.0.0.6 up
> > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > root@amd:~#
> > > >
> > > > It looks like it uses "a bit too big" allocations to allocate
> > > > firmware...? Order five allocation....
> > > >
> > > > Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> > > > network works. Is it VM problem that it failed to allocate memory when
> > > > it was freeable?
> > > >
> > >
> > > Do you have CONFIG_COMPACTION enabled?
> >
> > Yes:
> >
> > pavel@amd:/data/l/linux-good$ zgrep CONFIG_COMPACTION /proc/config.gz
> > CONFIG_COMPACTION=y
>
> Asking for a 256k allocation is pretty crazy - this is an operating
> system kernel, not a userspace application.
>
> I'm wondering if this is due to a recent change, but I'm having trouble
> working out where the allocation call site is.

iwlwifi/iwlegacy do such kind of allocation for ages, since iwlwifi driver
inclusion in 2.6.24 (however firmware was smaller then).

I can fix that in iwlegacy similar as Johannes did it in iwlwifi, but this
actually seems to be allocator regression. We use GFP_KERNEL allocation,
kernel can wait for free memory and/or swap out pages, I do not understand
why this fail.

Stanislaw

2012-09-11 23:25:39

by Andrew Morton

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Mon, 10 Sep 2012 13:11:13 +0200
Pavel Machek <[email protected]> wrote:

> On Sun 2012-09-09 15:40:55, David Rientjes wrote:
> > On Sun, 9 Sep 2012, Pavel Machek wrote:
> >
> > > On 3.6.0-rc2+, I tried to turn on the wireless, but got
> > >
> > > root@amd:~# ifconfig wlan0 10.0.0.6 up
> > > SIOCSIFFLAGS: Cannot allocate memory
> > > SIOCSIFFLAGS: Cannot allocate memory
> > > root@amd:~#
> > >
> > > It looks like it uses "a bit too big" allocations to allocate
> > > firmware...? Order five allocation....
> > >
> > > Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> > > network works. Is it VM problem that it failed to allocate memory when
> > > it was freeable?
> > >
> >
> > Do you have CONFIG_COMPACTION enabled?
>
> Yes:
>
> pavel@amd:/data/l/linux-good$ zgrep CONFIG_COMPACTION /proc/config.gz
> CONFIG_COMPACTION=y

Asking for a 256k allocation is pretty crazy - this is an operating
system kernel, not a userspace application.

I'm wondering if this is due to a recent change, but I'm having trouble
working out where the allocation call site is.

2012-09-12 06:53:48

by Johannes Berg

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Tue, 2012-09-11 at 22:57 -0700, Marc MERLIN wrote:
> On Wed, Sep 12, 2012 at 07:16:28AM +0200, Eric Dumazet wrote:
> > On Tue, 2012-09-11 at 16:25 -0700, Andrew Morton wrote:
> >
> > > Asking for a 256k allocation is pretty crazy - this is an operating
> > > system kernel, not a userspace application.
> > >
> > > I'm wondering if this is due to a recent change, but I'm having trouble
> > > working out where the allocation call site is.
> > > --
> >
> > (Adding Marc Merlin to CC, since he reported same problem)
> >
> > Thats the firmware loading in iwlwifi driver. Not sure if it can use SG.
> >
> > drivers/net/wireless/iwlwifi/iwl-drv.c
> >
> > iwl_alloc_ucode() -> iwl_alloc_fw_desc() -> dma_alloc_coherent()
> >
> > It seems some sections of /lib/firmware/iwlwifi*.ucode files are above
> > 128 Kbytes, so dma_alloc_coherent() try order-5 allocations
>
> Thanks for looping me in, yes, this looks very familiar to me :)
>
> In the other thread, Johannes Berg gave me this patch which is supposed to
> help: http://p.sipsolutions.net/11ea33b376a5bac5.txt

Yes, but that patch won't apply to iwlegacy as is. However, I'm pretty
sure that it should be possible to solve the issue in the same way in
iwlegacy.

johannes


2012-09-10 11:11:17

by Pavel Machek

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Sun 2012-09-09 15:40:55, David Rientjes wrote:
> On Sun, 9 Sep 2012, Pavel Machek wrote:
>
> > On 3.6.0-rc2+, I tried to turn on the wireless, but got
> >
> > root@amd:~# ifconfig wlan0 10.0.0.6 up
> > SIOCSIFFLAGS: Cannot allocate memory
> > SIOCSIFFLAGS: Cannot allocate memory
> > root@amd:~#
> >
> > It looks like it uses "a bit too big" allocations to allocate
> > firmware...? Order five allocation....
> >
> > Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> > network works. Is it VM problem that it failed to allocate memory when
> > it was freeable?
> >
>
> Do you have CONFIG_COMPACTION enabled?

Yes:

pavel@amd:/data/l/linux-good$ zgrep CONFIG_COMPACTION /proc/config.gz
CONFIG_COMPACTION=y
Pavel

--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

2012-09-24 09:14:34

by Johannes Berg

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Mon, 2012-09-24 at 12:03 +0300, Dan Carpenter wrote:

> > > > iwl_alloc_ucode() -> iwl_alloc_fw_desc() -> dma_alloc_coherent()
>
> I'm filing bugzilla entries for regressions. What's the status on
> this?

It looks like a VM change caused it, but I merged a patch for -next to
not require such large DMA allocations any more.

johannes


2012-09-09 22:40:59

by David Rientjes

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Sun, 9 Sep 2012, Pavel Machek wrote:

> On 3.6.0-rc2+, I tried to turn on the wireless, but got
>
> root@amd:~# ifconfig wlan0 10.0.0.6 up
> SIOCSIFFLAGS: Cannot allocate memory
> SIOCSIFFLAGS: Cannot allocate memory
> root@amd:~#
>
> It looks like it uses "a bit too big" allocations to allocate
> firmware...? Order five allocation....
>
> Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> network works. Is it VM problem that it failed to allocate memory when
> it was freeable?
>

Do you have CONFIG_COMPACTION enabled?

> iwl3945 0000:03:00.0: failed to allocate pci memory
> iwl3945 0000:03:00.0: Could not read microcode: -12
> firmware 0000:03:00.0: firmware_loading_store: vmap() failed
> iwl3945 0000:03:00.0: iwlwifi-3945-2.ucode firmware file req failed:
> -2
> iwl3945 0000:03:00.0: Loaded firmware iwlwifi-3945-1.ucode, which is
> deprecated. Please use API v2 instead.
> iwl3945 0000:03:00.0: loaded firmware version 15.32.2.9
> ifconfig: page allocation failure: order:5, mode:0x80d0
> Pid: 21116, comm: ifconfig Tainted: G W 3.6.0-rc2+ #228
> Call Trace:
> [<c029ebf6>] warn_alloc_failed+0xb6/0x100
> [<c02a0321>] __alloc_pages_nodemask+0x4c1/0x6e0
> [<c020699c>] dma_generic_alloc_coherent+0x8c/0xc0
> [<c05c4d59>] il3945_mac_start+0x1269/0x1280
> [<c0206910>] ? dma_generic_free_coherent+0x30/0x30
> [<c0800f64>] ? packet_notifier+0xc4/0x1a0
> [<c088094c>] ieee80211_do_open+0x28c/0x840
> [<c087f399>] ? ieee80211_check_concurrent_iface+0x19/0x190
> [<c024c7ea>] ? raw_notifier_call_chain+0x1a/0x20
> [<c0880f3b>] ieee80211_open+0x3b/0x80
> [<c0769966>] __dev_open+0x96/0xf0
> [<c08c73a5>] ? _raw_spin_unlock_bh+0x25/0x30
> [<c076633d>] __dev_change_flags+0x7d/0x150
> [<c076988e>] dev_change_flags+0x1e/0x60
> [<c07d819d>] devinet_ioctl+0x69d/0x770
> [<c076b026>] ? dev_ioctl+0x336/0x740
> [<c07d959a>] inet_ioctl+0x9a/0xc0
> [<c0756a33>] sock_ioctl+0x63/0x240
> [<c07569d0>] ? sock_fasync+0x80/0x80
> [<c02d91a3>] do_vfs_ioctl+0x83/0x570
> [<c0223a50>] ? mm_fault_error+0x170/0x170
> [<c024ba86>] ? up_read+0x16/0x30
> [<c0223bcc>] ? do_page_fault+0x17c/0x3b0
> [<c02d96c9>] sys_ioctl+0x39/0x70
> [<c08c7c10>] sysenter_do_call+0x12/0x31
> Mem-Info:
> DMA per-cpu:
> CPU 0: hi: 0, btch: 1 usd: 0
> CPU 1: hi: 0, btch: 1 usd: 0
> Normal per-cpu:
> CPU 0: hi: 186, btch: 31 usd: 30
> CPU 1: hi: 186, btch: 31 usd: 0
> HighMem per-cpu:
> CPU 0: hi: 186, btch: 31 usd: 0
> CPU 1: hi: 186, btch: 31 usd: 0
> active_anon:250783 inactive_anon:118977 isolated_anon:0
> active_file:14686 inactive_file:13826 isolated_file:0
> unevictable:0 dirty:3050 writeback:0 unstable:0
> free:30113 slab_reclaimable:43820 slab_unreclaimable:34426
> mapped:11898 shmem:19084 pagetables:3043 bounce:0
> DMA free:1580kB min:64kB low:80kB high:96kB active_anon:0kB
> inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB
> isolated(anon):0kB isolated(file):0kB present:15788kB 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
> lowmem_reserve[]: 0 864 2005 2005
> Normal free:115348kB min:3728kB low:4660kB high:5592kB
> active_anon:193616kB inactive_anon:192540kB active_file:19528kB
> inactive_file:12916kB unevictable:0kB isolated(anon):0kB
> isolated(file):0kB present:885072kB mlocked:0kB dirty:5388kB
> writeback:0kB mapped:9212kB shmem:29100kB slab_reclaimable:175280kB
> slab_unreclaimable:137704kB kernel_stack:6032kB pagetables:12172kB
> unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
> all_unreclaimable? no
> lowmem_reserve[]: 0 0 9125 9125
> HighMem free:3524kB min:512kB low:1740kB high:2972kB
> active_anon:809516kB inactive_anon:283368kB active_file:39216kB
> inactive_file:42388kB unevictable:0kB isolated(anon):0kB
> isolated(file):0kB present:1168080kB mlocked:0kB dirty:6812kB
> writeback:0kB mapped:38380kB shmem:47236kB slab_reclaimable:0kB
> slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB
> bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> lowmem_reserve[]: 0 0 0 0
> DMA: 1*4kB 1*8kB 0*16kB 1*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB
> 0*2048kB 0*4096kB = 1580kB
> Normal: 4729*4kB 8354*8kB 1683*16kB 74*32kB 4*64kB 0*128kB 0*256kB
> 0*512kB 0*1024kB 0*2048kB 0*4096kB = 115300kB
> HighMem: 537*4kB 118*8kB 27*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB
> 0*1024kB 0*2048kB 0*4096kB = 3524kB
> 62305 total pagecache pages
> 14672 pages in swap cache
> Swap cache stats: add 96156, delete 81484, find 3042279/3044117
> Free swap = 480024kB
> Total swap = 779148kB
> 521920 pages RAM
> 294610 pages HighMem
> 9083 pages reserved
> 244243 pages shared
> 450983 pages non-shared
> iwl3945 0000:03:00.0: failed to allocate pci memory
> iwl3945 0000:03:00.0: Could not read microcode: -12

2012-09-12 05:57:27

by Marc MERLIN

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Wed, Sep 12, 2012 at 07:16:28AM +0200, Eric Dumazet wrote:
> On Tue, 2012-09-11 at 16:25 -0700, Andrew Morton wrote:
>
> > Asking for a 256k allocation is pretty crazy - this is an operating
> > system kernel, not a userspace application.
> >
> > I'm wondering if this is due to a recent change, but I'm having trouble
> > working out where the allocation call site is.
> > --
>
> (Adding Marc Merlin to CC, since he reported same problem)
>
> Thats the firmware loading in iwlwifi driver. Not sure if it can use SG.
>
> drivers/net/wireless/iwlwifi/iwl-drv.c
>
> iwl_alloc_ucode() -> iwl_alloc_fw_desc() -> dma_alloc_coherent()
>
> It seems some sections of /lib/firmware/iwlwifi*.ucode files are above
> 128 Kbytes, so dma_alloc_coherent() try order-5 allocations

Thanks for looping me in, yes, this looks very familiar to me :)

In the other thread, Johannes Berg gave me this patch which is supposed to
help: http://p.sipsolutions.net/11ea33b376a5bac5.txt

Unfortunately due to very long work days, I haven't had the time to try it
out yet, but I will soon.

Would that help in this case too?

And to answer David Rientjes, I also have compaction on:
gandalfthegreat:~# zgrep CONFIG_COMPACTION /proc/config.gz
CONFIG_COMPACTION=y

Full config:
http://marc.merlins.org/tmp/config-3.5.2-amd64-preempt-noide-20120731

If that helps for comparison, my thread is here:
http://www.spinics.net/lists/linux-wireless/msg96438.html

Thanks,
Marc
--
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
.... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/

2012-09-24 09:04:35

by Dan Carpenter

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Wed, Sep 12, 2012 at 08:54:06AM +0200, Johannes Berg wrote:
> On Tue, 2012-09-11 at 22:57 -0700, Marc MERLIN wrote:
> > On Wed, Sep 12, 2012 at 07:16:28AM +0200, Eric Dumazet wrote:
> > > On Tue, 2012-09-11 at 16:25 -0700, Andrew Morton wrote:
> > >
> > > > Asking for a 256k allocation is pretty crazy - this is an operating
> > > > system kernel, not a userspace application.
> > > >
> > > > I'm wondering if this is due to a recent change, but I'm having trouble
> > > > working out where the allocation call site is.
> > > > --
> > >
> > > (Adding Marc Merlin to CC, since he reported same problem)
> > >
> > > Thats the firmware loading in iwlwifi driver. Not sure if it can use SG.
> > >
> > > drivers/net/wireless/iwlwifi/iwl-drv.c
> > >
> > > iwl_alloc_ucode() -> iwl_alloc_fw_desc() -> dma_alloc_coherent()

I'm filing bugzilla entries for regressions. What's the status on
this?

regards,
dan carpenter


2012-09-12 10:18:32

by Mel Gorman

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Tue, Sep 11, 2012 at 04:25:36PM -0700, Andrew Morton wrote:
> On Mon, 10 Sep 2012 13:11:13 +0200
> Pavel Machek <[email protected]> wrote:
>
> > On Sun 2012-09-09 15:40:55, David Rientjes wrote:
> > > On Sun, 9 Sep 2012, Pavel Machek wrote:
> > >
> > > > On 3.6.0-rc2+, I tried to turn on the wireless, but got
> > > >
> > > > root@amd:~# ifconfig wlan0 10.0.0.6 up
> > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > root@amd:~#
> > > >
> > > > It looks like it uses "a bit too big" allocations to allocate
> > > > firmware...? Order five allocation....
> > > >
> > > > Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> > > > network works. Is it VM problem that it failed to allocate memory when
> > > > it was freeable?
> > > >
> > >
> > > Do you have CONFIG_COMPACTION enabled?
> >
> > Yes:
> >
> > pavel@amd:/data/l/linux-good$ zgrep CONFIG_COMPACTION /proc/config.gz
> > CONFIG_COMPACTION=y
>
> Asking for a 256k allocation is pretty crazy - this is an operating
> system kernel, not a userspace application.
>
> I'm wondering if this is due to a recent change, but I'm having trouble
> working out where the allocation call site is.

It may be indirectly due to a recent change and this was somewhat
deliberate. Order-5 is larger than PAGE_ALLOC_COSTLY_ORDER and I doubt
__GFP_REPEAT was set so it is treated as something that can fail in
preference to aggressively reclaiming pages to satisfy the allocation. In
older kernels with lumpy reclaim and an aggressive kswapd it would have
probably succeeded but now it errs on the side of failing early instead
assuming that the caller can recover. Drivers that depend on order-5
allocations to succeed for correct operation are somewhat frowned upon.

--
Mel Gorman
SUSE Labs

2012-09-12 05:16:35

by Eric Dumazet

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Tue, 2012-09-11 at 16:25 -0700, Andrew Morton wrote:

> Asking for a 256k allocation is pretty crazy - this is an operating
> system kernel, not a userspace application.
>
> I'm wondering if this is due to a recent change, but I'm having trouble
> working out where the allocation call site is.
> --

(Adding Marc Merlin to CC, since he reported same problem)

Thats the firmware loading in iwlwifi driver. Not sure if it can use SG.

drivers/net/wireless/iwlwifi/iwl-drv.c

iwl_alloc_ucode() -> iwl_alloc_fw_desc() -> dma_alloc_coherent()

It seems some sections of /lib/firmware/iwlwifi*.ucode files are above
128 Kbytes, so dma_alloc_coherent() try order-5 allocations


# ls -l /lib/firmware/iwlwifi*.ucode
-rw-r--r-- 1 root root 335056 2012-01-23 18:20 /lib/firmware/iwlwifi-1000-3.ucode
-rw-r--r-- 1 root root 337520 2012-01-23 18:20 /lib/firmware/iwlwifi-1000-5.ucode
-rw-r--r-- 1 root root 689680 2012-01-24 19:18 /lib/firmware/iwlwifi-105-6.ucode
-rw-r--r-- 1 root root 701228 2012-01-24 19:18 /lib/firmware/iwlwifi-135-6.ucode
-rw-r--r-- 1 root root 695876 2012-01-24 19:19 /lib/firmware/iwlwifi-2000-6.ucode
-rw-r--r-- 1 root root 707392 2012-01-24 19:19 /lib/firmware/iwlwifi-2030-6.ucode
-rw-r--r-- 1 root root 150100 2012-01-23 18:20 /lib/firmware/iwlwifi-3945-2.ucode
-rw-r--r-- 1 root root 187972 2012-01-23 18:20 /lib/firmware/iwlwifi-4965-2.ucode
-rw-r--r-- 1 root root 345008 2012-01-23 18:20 /lib/firmware/iwlwifi-5000-1.ucode
-rw-r--r-- 1 root root 353240 2012-01-23 18:20 /lib/firmware/iwlwifi-5000-2.ucode
-rw-r--r-- 1 root root 340696 2012-01-23 18:21 /lib/firmware/iwlwifi-5000-5.ucode
-rw-r--r-- 1 root root 337400 2012-01-23 18:20 /lib/firmware/iwlwifi-5150-2.ucode
-rw-r--r-- 1 root root 462280 2012-01-24 19:20 /lib/firmware/iwlwifi-6000-4.ucode
-rw-r--r-- 1 root root 444128 2012-01-24 19:20 /lib/firmware/iwlwifi-6000g2a-5.ucode
-rw-r--r-- 1 root root 460912 2012-01-24 19:20 /lib/firmware/iwlwifi-6000g2b-5.ucode
-rw-r--r-- 1 root root 679436 2012-01-24 19:19 /lib/firmware/iwlwifi-6000g2b-6.ucode
-rw-r--r-- 1 root root 463692 2012-01-23 18:20 /lib/firmware/iwlwifi-6050-4.ucode
-rw-r--r-- 1 root root 469780 2012-01-23 18:20 /lib/firmware/iwlwifi-6050-5.ucode



2012-10-08 15:40:42

by Stanislaw Gruszka

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Sat, Oct 06, 2012 at 02:08:50PM +0200, Pavel Machek wrote:
> On Fri 2012-10-05 10:37:00, Stanislaw Gruszka wrote:
> > On Wed, Oct 03, 2012 at 11:07:13AM -0700, David Rientjes wrote:
> > > On Wed, 3 Oct 2012, Stanislaw Gruszka wrote:
> > >
> > > > So, can this problem be solved like on below patch, or I should rather
> > > > split firmware loading into chunks similar like was already iwlwifi did?
> >
> > Hmm, I looked at iwl3945 code and looks loading firmware in chunks is
> > nothing that can be easily done. 3945 bootstrap code expect that runtime
> > ucode will be placed in physically continue memory, and there are no
> > separate instructions for copy and for execute, just one to perform both
> > those actions. Maybe loading firmware in chunks can be done using
> > undocumented features of the device, but I'm eager to do this.
>
> Just allocate memory during boot?

On driver I can reserve memory during module load, but also this isn't
something I prefer to do.

> > Pavel, do you still can reproduce this problem on released 3.6 ?
>
> It happened again yesterday on 3.6.0-rc6+. I don't think mm changed
> between -rc6 and final...

Could you check __GFP_REPEAT oneline patch posted previously ?
And if that fail again, provide full dmesg (on your previous messages
there is vmap() failure, which I do not understand, where it come
from) ?

Thanks
Stanislaw

2012-10-06 12:08:53

by Pavel Machek

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

Hi!
On Fri 2012-10-05 10:37:00, Stanislaw Gruszka wrote:
> On Wed, Oct 03, 2012 at 11:07:13AM -0700, David Rientjes wrote:
> > On Wed, 3 Oct 2012, Stanislaw Gruszka wrote:
> >
> > > So, can this problem be solved like on below patch, or I should rather
> > > split firmware loading into chunks similar like was already iwlwifi did?
>
> Hmm, I looked at iwl3945 code and looks loading firmware in chunks is
> nothing that can be easily done. 3945 bootstrap code expect that runtime
> ucode will be placed in physically continue memory, and there are no
> separate instructions for copy and for execute, just one to perform both
> those actions. Maybe loading firmware in chunks can be done using
> undocumented features of the device, but I'm eager to do this.

Just allocate memory during boot?

> Pavel, do you still can reproduce this problem on released 3.6 ?

It happened again yesterday on 3.6.0-rc6+. I don't think mm changed
between -rc6 and final...
Pavel
--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

2012-10-03 18:07:15

by David Rientjes

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Wed, 3 Oct 2012, Stanislaw Gruszka wrote:

> So, can this problem be solved like on below patch, or I should rather
> split firmware loading into chunks similar like was already iwlwifi did?
>
> diff --git a/drivers/net/wireless/iwlegacy/common.h b/drivers/net/wireless/iwlegacy/common.h
> index 5f50177..1b58222 100644
> --- a/drivers/net/wireless/iwlegacy/common.h
> +++ b/drivers/net/wireless/iwlegacy/common.h
> @@ -2247,7 +2247,7 @@ il_alloc_fw_desc(struct pci_dev *pci_dev, struct fw_desc *desc)
>
> desc->v_addr =
> dma_alloc_coherent(&pci_dev->dev, desc->len, &desc->p_addr,
> - GFP_KERNEL);
> + GFP_KERNEL | __GFP_REPEAT);
> return (desc->v_addr != NULL) ? 0 : -ENOMEM;
> }
>

I think this will certainly make memory compaction more aggressive by
avoiding the logic to defer calling compaction in the page allocator, but
because we lack lumpy reclaim this still has a higher probability of
failing than it had in the past because it will fail if 128KB of memory is
reclaimed that may not happen to be contiguous for an order-5 allocation
to succeed.

2012-10-03 11:37:59

by Stanislaw Gruszka

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Wed, Sep 12, 2012 at 11:18:26AM +0100, Mel Gorman wrote:
> On Tue, Sep 11, 2012 at 04:25:36PM -0700, Andrew Morton wrote:
> > On Mon, 10 Sep 2012 13:11:13 +0200
> > Pavel Machek <[email protected]> wrote:
> >
> > > On Sun 2012-09-09 15:40:55, David Rientjes wrote:
> > > > On Sun, 9 Sep 2012, Pavel Machek wrote:
> > > >
> > > > > On 3.6.0-rc2+, I tried to turn on the wireless, but got
> > > > >
> > > > > root@amd:~# ifconfig wlan0 10.0.0.6 up
> > > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > > SIOCSIFFLAGS: Cannot allocate memory
> > > > > root@amd:~#
> > > > >
> > > > > It looks like it uses "a bit too big" allocations to allocate
> > > > > firmware...? Order five allocation....
> > > > >
> > > > > Hmm... then I did "echo 3 > /proc/sys/vm/drop_caches" and now the
> > > > > network works. Is it VM problem that it failed to allocate memory when
> > > > > it was freeable?
> > > > >
> > > >
> > > > Do you have CONFIG_COMPACTION enabled?
> > >
> > > Yes:
> > >
> > > pavel@amd:/data/l/linux-good$ zgrep CONFIG_COMPACTION /proc/config.gz
> > > CONFIG_COMPACTION=y
> >
> > Asking for a 256k allocation is pretty crazy - this is an operating
> > system kernel, not a userspace application.
> >
> > I'm wondering if this is due to a recent change, but I'm having trouble
> > working out where the allocation call site is.
>
> It may be indirectly due to a recent change and this was somewhat
> deliberate. Order-5 is larger than PAGE_ALLOC_COSTLY_ORDER and I doubt
> __GFP_REPEAT was set so it is treated as something that can fail in
> preference to aggressively reclaiming pages to satisfy the allocation. In
> older kernels with lumpy reclaim and an aggressive kswapd it would have
> probably succeeded but now it errs on the side of failing early instead
> assuming that the caller can recover. Drivers that depend on order-5
> allocations to succeed for correct operation are somewhat frowned upon.

So, can this problem be solved like on below patch, or I should rather
split firmware loading into chunks similar like was already iwlwifi did?

diff --git a/drivers/net/wireless/iwlegacy/common.h b/drivers/net/wireless/iwlegacy/common.h
index 5f50177..1b58222 100644
--- a/drivers/net/wireless/iwlegacy/common.h
+++ b/drivers/net/wireless/iwlegacy/common.h
@@ -2247,7 +2247,7 @@ il_alloc_fw_desc(struct pci_dev *pci_dev, struct fw_desc *desc)

desc->v_addr =
dma_alloc_coherent(&pci_dev->dev, desc->len, &desc->p_addr,
- GFP_KERNEL);
+ GFP_KERNEL | __GFP_REPEAT);
return (desc->v_addr != NULL) ? 0 : -ENOMEM;
}


2012-10-05 08:38:17

by Stanislaw Gruszka

[permalink] [raw]
Subject: Re: iwl3945: order 5 allocation during ifconfig up; vm problem?

On Wed, Oct 03, 2012 at 11:07:13AM -0700, David Rientjes wrote:
> On Wed, 3 Oct 2012, Stanislaw Gruszka wrote:
>
> > So, can this problem be solved like on below patch, or I should rather
> > split firmware loading into chunks similar like was already iwlwifi did?

Hmm, I looked at iwl3945 code and looks loading firmware in chunks is
nothing that can be easily done. 3945 bootstrap code expect that runtime
ucode will be placed in physically continue memory, and there are no
separate instructions for copy and for execute, just one to perform both
those actions. Maybe loading firmware in chunks can be done using
undocumented features of the device, but I'm eager to do this.

> > diff --git a/drivers/net/wireless/iwlegacy/common.h b/drivers/net/wireless/iwlegacy/common.h
> > index 5f50177..1b58222 100644
> > --- a/drivers/net/wireless/iwlegacy/common.h
> > +++ b/drivers/net/wireless/iwlegacy/common.h
> > @@ -2247,7 +2247,7 @@ il_alloc_fw_desc(struct pci_dev *pci_dev, struct fw_desc *desc)
> >
> > desc->v_addr =
> > dma_alloc_coherent(&pci_dev->dev, desc->len, &desc->p_addr,
> > - GFP_KERNEL);
> > + GFP_KERNEL | __GFP_REPEAT);
> > return (desc->v_addr != NULL) ? 0 : -ENOMEM;
> > }
> >
>
> I think this will certainly make memory compaction more aggressive by
> avoiding the logic to defer calling compaction in the page allocator, but
> because we lack lumpy reclaim this still has a higher probability of
> failing than it had in the past because it will fail if 128KB of memory is
> reclaimed that may not happen to be contiguous for an order-5 allocation
> to succeed.

I understand that complex systems like virtual memory manager require
various design compromises. In this case decision was to make memory
allocator to perform faster in cost of possible allocation failures.
I'm not quite sure if that was good decision, but I think VM developers
know best what is good for VM.

However, maybe this allocation issue initially reported here, was
caused by some bug, which is possibly now fixed i.e. memory leak on
some driver or subsystem.

Pavel, do you still can reproduce this problem on released 3.6 ?

Thanks
Stanislaw