Bug 19752 - dhcpcd and ip cannot allocate memory on r8169 (RTL8101E/RTL8102E)
Summary: dhcpcd and ip cannot allocate memory on r8169 (RTL8101E/RTL8102E)
Status: RESOLVED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: Network (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Francois Romieu
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-10-04 21:17 UTC by Alexander Lam
Modified: 2011-08-04 09:54 UTC (History)
2 users (show)

See Also:
Kernel Version: 2.6.35.7
Subsystem:
Regression: No
Bisected commit-id:


Attachments
Full dmesg output (93.17 KB, text/plain)
2010-10-04 21:17 UTC, Alexander Lam
Details
lspci -vvv (27.60 KB, text/plain)
2010-10-04 21:18 UTC, Alexander Lam
Details
r8169: allocate with GFP_KERNEL flag when able to sleep (2.44 KB, patch)
2010-10-04 22:39 UTC, Francois Romieu
Details | Diff

Description Alexander Lam 2010-10-04 21:17:16 UTC
Created attachment 32552 [details]
Full dmesg output

When my system tries to obtain a DHCP lease using dhcpcd 5.2.7, the dmesg output at the bottom of this comment will appear.
This error seldom occurs, but once it appears once, it will keep dhcpcd from completing until the system is rebooted.

Additionally, obtaining a dhcp lease on wifi is always reliable.

note that I am running a custom memory split (so I don't have to use highmem on my 1GB machine)

I do not know if this is a regression because I only started using my ethernet card recently (the past month or so).

Attached is lspci and full dmesg output.
I am running 2.6.35.7, not 2.6.35 as the dmesg output says (when building the kernel the minor number gets stripped).

If I have not assigned this bug to the right component, please reassign.

[12471.614232] r8169 0000:02:00.0: PME# disabled
[12471.614465] ip: page allocation failure. order:3, mode:0x4020
[12471.614477] Pid: 21938, comm: ip Not tainted 2.6.35-aao #1
[12471.614483] Call Trace:
[12471.614502]  [<b107a758>] ? __alloc_pages_nodemask+0x3f8/0x590
[12471.614516]  [<b107a905>] ? __get_free_pages+0x15/0x40
[12471.614528]  [<b1253409>] ? __alloc_skb+0x59/0x100
[12471.614538]  [<b125435c>] ? __netdev_alloc_skb+0x1c/0x40
[12471.614554]  [<f0707244>] ? rtl8169_rx_fill+0xa4/0x1e0 [r8169]
[12471.614569]  [<f07073e1>] ? rtl8169_init_ring+0x61/0xa0 [r8169]
[12471.614582]  [<f07075b6>] ? rtl8169_open+0xc6/0x470 [r8169]
[12471.614594]  [<b104ba86>] ? notifier_call_chain+0x46/0x60
[12471.614605]  [<b1006d60>] ? dma_generic_alloc_coherent+0x0/0xd0
[12471.614617]  [<b125cb73>] ? __dev_open+0xa3/0xf0
[12471.614626]  [<b125cab1>] ? dev_set_rx_mode+0x21/0x40
[12471.614636]  [<b125cdda>] ? __dev_change_flags+0x8a/0x170
[12471.614647]  [<b125cf5c>] ? dev_change_flags+0x1c/0x60
[12471.614657]  [<b12667bf>] ? do_setlink+0x17f/0x720
[12471.614669]  [<b115889e>] ? nla_parse+0x1e/0xb0
[12471.614680]  [<b1267d11>] ? rtnl_newlink+0x361/0x480
[12471.614692]  [<b109048d>] ? page_add_new_anon_rmap+0x4d/0x90
[12471.614706]  [<b1266000>] ? rtnl_fill_ifinfo+0x2a0/0x670
[12471.614726]  [<b10204d0>] ? do_page_fault+0x0/0x370
[12471.614736]  [<b131072b>] ? error_code+0x73/0x78
[12471.614747]  [<b12679b0>] ? rtnl_newlink+0x0/0x480
[12471.614758]  [<b12676ee>] ? rtnetlink_rcv_msg+0x1ee/0x220
[12471.614768]  [<b124feac>] ? sock_rmalloc+0x4c/0x90
[12471.614779]  [<b1267500>] ? rtnetlink_rcv_msg+0x0/0x220
[12471.614789]  [<b12760a6>] ? netlink_rcv_skb+0x86/0xa0
[12471.614800]  [<b1267440>] ? rtnetlink_rcv+0x0/0x20
[12471.614810]  [<b1267454>] ? rtnetlink_rcv+0x14/0x20
[12471.614820]  [<b1275ac2>] ? netlink_unicast+0x242/0x280
[12471.614830]  [<b1275ca8>] ? netlink_sendmsg+0x1a8/0x2a0
[12471.614842]  [<b124b4cf>] ? sock_sendmsg+0x9f/0xd0
[12471.614855]  [<b107a11a>] ? get_page_from_freelist+0x21a/0x460
[12471.614866]  [<b1254fe2>] ? verify_iovec+0x52/0x90
[12471.614877]  [<b124d198>] ? sys_sendmsg+0x178/0x260
[12471.614891]  [<b108a308>] ? handle_mm_fault+0x358/0x620
[12471.614902]  [<b114f519>] ? rb_insert_color+0x79/0x100
[12471.614913]  [<b124d2ba>] ? sys_recvmsg+0x3a/0x70
[12471.614925]  [<b124d672>] ? sys_socketcall+0xe2/0x2a0
[12471.614935]  [<b10204d0>] ? do_page_fault+0x0/0x370
[12471.614945]  [<b1002c57>] ? sysenter_do_call+0x12/0x26
[12471.614952] Mem-Info:
[12471.614957] DMA per-cpu:
[12471.614964] CPU    0: hi:    0, btch:   1 usd:   0
[12471.614971] CPU    1: hi:    0, btch:   1 usd:   0
[12471.614976] Normal per-cpu:
[12471.614983] CPU    0: hi:  186, btch:  31 usd: 120
[12471.614990] CPU    1: hi:  186, btch:  31 usd: 163
[12471.615005] active_anon:19330 inactive_anon:21077 isolated_anon:0
[12471.615009]  active_file:82969 inactive_file:112812 isolated_file:0
[12471.615012]  unevictable:0 dirty:2312 writeback:0 unstable:0
[12471.615012]  free:3875 slab_reclaimable:10297 slab_unreclaimable:1534
[12471.615012]  mapped:8131 shmem:11138 pagetables:354 bounce:0
[12471.615066] DMA free:3988kB min:60kB low:72kB high:88kB active_anon:0kB inactive_anon:0kB active_file:416kB inactive_file:10400kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:140kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[12471.615085] lowmem_reserve[]: 0 988 988
[12471.615109] Normal free:11512kB min:3988kB low:4984kB high:5980kB active_anon:77320kB inactive_anon:84308kB active_file:331460kB inactive_file:440848kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1012272kB mlocked:0kB dirty:9248kB writeback:0kB mapped:32524kB shmem:44552kB slab_reclaimable:41048kB slab_unreclaimable:6136kB kernel_stack:1520kB pagetables:1416kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[12471.615130] lowmem_reserve[]: 0 0 0
[12471.615139] DMA: 123*4kB 1*8kB 0*16kB 1*32kB 0*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 0*4096kB = 3988kB
[12471.615167] Normal: 2698*4kB 2*8kB 8*16kB 0*32kB 1*64kB 0*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 11512kB
[12471.615194] 206937 total pagecache pages
[12471.615200] 0 pages in swap cache
[12471.615206] Swap cache stats: add 0, delete 0, find 0/0
[12471.615212] Free swap  = 2056252kB
[12471.615217] Total swap = 2056252kB
[12471.641617] 259327 pages RAM
[12471.641626] 4048 pages reserved
[12471.641631] 207677 pages shared
[12471.641635] 56726 pages non-shared
[12473.693652] dhcpcd: page allocation failure. order:3, mode:0x4020
[12473.693665] Pid: 21943, comm: dhcpcd Not tainted 2.6.35-aao #1
[12473.693671] Call Trace:
[12473.693687]  [<b107a758>] ? __alloc_pages_nodemask+0x3f8/0x590
[12473.693698]  [<b107a905>] ? __get_free_pages+0x15/0x40
[12473.693710]  [<b1253409>] ? __alloc_skb+0x59/0x100
[12473.693721]  [<b125435c>] ? __netdev_alloc_skb+0x1c/0x40
[12473.693739]  [<f0707244>] ? rtl8169_rx_fill+0xa4/0x1e0 [r8169]
[12473.693752]  [<f07073e1>] ? rtl8169_init_ring+0x61/0xa0 [r8169]
[12473.693764]  [<f07075b6>] ? rtl8169_open+0xc6/0x470 [r8169]
[12473.693777]  [<b104ba86>] ? notifier_call_chain+0x46/0x60
[12473.693788]  [<b1006d60>] ? dma_generic_alloc_coherent+0x0/0xd0
[12473.693799]  [<b125cb73>] ? __dev_open+0xa3/0xf0
[12473.693809]  [<b125cab1>] ? dev_set_rx_mode+0x21/0x40
[12473.693818]  [<b125cdda>] ? __dev_change_flags+0x8a/0x170
[12473.693827]  [<b125abc5>] ? dev_get_by_name_rcu+0x75/0x90
[12473.693838]  [<b125cf5c>] ? dev_change_flags+0x1c/0x60
[12473.693849]  [<b12a6fdb>] ? devinet_ioctl+0x62b/0x790
[12473.693858]  [<b125abc5>] ? dev_get_by_name_rcu+0x75/0x90
[12473.693870]  [<b124af96>] ? sock_ioctl+0x66/0x250
[12473.693882]  [<b10ad7f9>] ? vfs_ioctl+0x39/0xb0
[12473.693892]  [<b124af30>] ? sock_ioctl+0x0/0x250
[12473.693901]  [<b10adfed>] ? do_vfs_ioctl+0x6d/0x570
[12473.693911]  [<b10b05b8>] ? d_kill+0x48/0x60
[12473.693920]  [<b10b0c84>] ? dput+0x84/0x120
[12473.693928]  [<b10a1c2a>] ? fput+0x16a/0x200
[12473.693939]  [<b10b6d93>] ? mntput_no_expire+0x13/0x90
[12473.693949]  [<b10ae52e>] ? sys_ioctl+0x3e/0x70
[12473.693958]  [<b1002c57>] ? sysenter_do_call+0x12/0x26
[12473.693965] Mem-Info:
[12473.693970] DMA per-cpu:
[12473.693976] CPU    0: hi:    0, btch:   1 usd:   0
[12473.693983] CPU    1: hi:    0, btch:   1 usd:   0
[12473.693988] Normal per-cpu:
[12473.693994] CPU    0: hi:  186, btch:  31 usd: 153
[12473.694001] CPU    1: hi:  186, btch:  31 usd: 178
[12473.694064] active_anon:19386 inactive_anon:21095 isolated_anon:0
[12473.694068]  active_file:83009 inactive_file:114422 isolated_file:32
[12473.694072]  unevictable:0 dirty:4535 writeback:0 unstable:0
[12473.694075]  free:2011 slab_reclaimable:10347 slab_unreclaimable:1534
[12473.694079]  mapped:8108 shmem:11157 pagetables:353 bounce:0
[12473.694103] DMA free:3988kB min:60kB low:72kB high:88kB active_anon:0kB inactive_anon:0kB active_file:416kB inactive_file:10400kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15864kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:140kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[12473.694120] lowmem_reserve[]: 0 988 988
[12473.694143] Normal free:4180kB min:3988kB low:4984kB high:5980kB active_anon:77544kB inactive_anon:84380kB active_file:331620kB inactive_file:447288kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:1012272kB mlocked:0kB dirty:18140kB writeback:0kB mapped:32432kB shmem:44628kB slab_reclaimable:41248kB slab_unreclaimable:6136kB kernel_stack:1560kB pagetables:1412kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[12473.694162] lowmem_reserve[]: 0 0 0
[12473.694170] DMA: 123*4kB 1*8kB 0*16kB 1*32kB 0*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 0*4096kB = 3988kB
[12473.694194] Normal: 863*4kB 5*8kB 7*16kB 0*32kB 1*64kB 0*128kB 0*256kB 1*512kB 0*1024kB 0*2048kB 0*4096kB = 4180kB
[12473.694217] 208616 total pagecache pages
[12473.694222] 0 pages in swap cache
[12473.694227] Swap cache stats: add 0, delete 0, find 0/0
[12473.694232] Free swap  = 2056252kB
[12473.694236] Total swap = 2056252kB
[12473.702639] 259327 pages RAM
[12473.702647] 4048 pages reserved
[12473.702652] 209434 pages shared
[12473.702656] 56766 pages non-shared
Comment 1 Alexander Lam 2010-10-04 21:18:31 UTC
Created attachment 32562 [details]
lspci -vvv
Comment 2 Alexander Lam 2010-10-04 21:19:49 UTC
I should also mention that this machine is an Acer Aspire One AOA150 (the original 9" version)

you can also see from the dmesg output that I have runtime PM on for the r8169 device.
Comment 3 Francois Romieu 2010-10-04 22:39:03 UTC
Created attachment 32572 [details]
r8169: allocate with GFP_KERNEL flag when able to sleep

Courtesy of Stanislaw Gruszka (see:
https://bugzilla.redhat.com/show_bug.cgi?id=629158).

It should help but it may not be easy to tell the difference between "it
fails sometimes" and "it has not failed yet".

Tips :
- https://bugzilla.redhat.com/show_bug.cgi?id=566389#c6
- increase vm.min_free_kbytes (sysctl)

-- 
Ueimor
Comment 4 Stanislaw Gruszka 2010-10-08 15:05:31 UTC
(In reply to comment #3)
> It should help but it may not be easy to tell the difference between "it
> fails sometimes" and "it has not failed yet".
If we will still have this problem, it will need to be fixed by memory management. However, without this change vm developers would tell us that the driver is broken. So we need that patch (and fix the another problem http://marc.info/?l=linux-netdev&m=128654946502077&w=2) to start talk to vm guys about fixing the issue, if it will not gone.

> Tips :
> - https://bugzilla.redhat.com/show_bug.cgi?id=566389#c6
> - increase vm.min_free_kbytes (sysctl)
Use SLAB, much more allocation problems are seen in SLUB.
Comment 5 Francois Romieu 2011-08-04 09:54:16 UTC
The driver does not 3-order allocate since commit
6f0333b8fde44b8c04a53b2461504f0e8f1cebe6 (Eric Dumazet) in v2.6.37 and there
remains no GFP_ATOMIC allocation.

Closing it for now.

-- 
Ueimor

Note You need to log in before you can comment on or make changes to this bug.