From: poma <pomidorabelisima@gmail.com>
To: netdev@vger.kernel.org, David Miller <davem@davemloft.net>,
Francois Romieu <romieu@fr.zoreil.com>,
Mike Massonnet <m8t@gandi.net>,
Benedikt Meurer <benedikt.meurer@unix-ag.uni-siegen.de>,
Bernhard Walle <bernhard.walle@gmx.de>,
Hendrik Scholz <hscholz@raisdorf.net>,
Florian Rivoal <frivoal@xfce.org>
Subject: Re: [PATCH net 1/1] r8169: fix sleepable allocation during netdevice stats retrieval.
Date: Thu, 10 Sep 2015 01:11:50 +0200 [thread overview]
Message-ID: <55F0BCB6.5030508@gmail.com> (raw)
In-Reply-To: <20150909190805.GA26699@calimero.vinschen.de>
On 09/09/2015 09:08 PM, Corinna Vinschen wrote:
> On Sep 9 20:34, poma wrote:
>> On 09/09/2015 05:55 PM, Corinna Vinschen wrote:
>>> On Sep 9 17:54, Corinna Vinschen wrote:
>>>> On Sep 9 17:24, poma wrote:
>>>>> [PATCH net] r8169: Fix sleeping function called during get_stats64
>>>>> http://marc.info/?l=linux-netdev&m=144180123410135&q=raw
>>>>> - the noise is still present
>>>>
>>>> Are you really sure? The entire dma_alloc/dma_free stuff has been moved
>>>> away. There's no locking or sleeping involved different from what was
>>>> there before my original patch when calling .ndo_get_stats64.
>>>>
>>
>>
>> It is literally the kernel ring buffer output,
>> so I really can not understand your question.
>
> I'm asking because I'm wondering if you're actually testing the
> right r8169.ko module, the one with the patch applied. See below.
>
I already explained the patching/building procedure
http://www.spinics.net/lists/netdev/msg342268.html
>>>> How would I be able to reproduce this on the command line?
>>
>> This I have already written, here's once more for you,
>> <quote>
>> This noise is induced via userspace, xfce4-netload-plugin,
>> http://goodies.xfce.org/projects/panel-plugins/xfce4-netload-plugin
>>
>> $ grep -i device .config/xfce4/panel/netload-16.rc
>> Network_Device=enp3s0
>>
>> $ ethtool -i enp3s0 | grep driver
>> driver: r8169
>> </quote>
>>
>> Therefore, to try to reproduce this issue, 'xfce4-netload-plugin' must run within 'xfce4-panel',
>> moreover 'xfce4-netload-plugin' must be configured to monitor affected network interface.
>
> I'lll see if I can try this tomorrow.
>
>> No command line this time, hombre.
>
This is how I managed to reproduce the noise within the CLI - via 'ifconfig',
no need to pre-configure interface:
# ifconfig enp3s0 up
# dmesg
[ 390.128904] r8169 0000:03:00.0 enp3s0: link down
[ 390.129669] IPv6: ADDRCONF(NETDEV_UP): enp3s0: link is not ready
# ifconfig
# dmesg
[ 393.855932] ===============================
[ 393.855937] [ INFO: suspicious RCU usage. ]
[ 393.855945] 4.3.0-0.rc0.git9.1.fc24.x86_64 #1 Not tainted
[ 393.855949] -------------------------------
[ 393.855956] include/linux/rcupdate.h:579 Illegal context switch in RCU read-side critical section!
[ 393.855960]
other info that might help us debug this:
[ 393.855970]
rcu_scheduler_active = 1, debug_locks = 0
[ 393.855977] 2 locks held by ifconfig/2642:
[ 393.855981] #0: (&p->lock){+.+.+.}, at: [<ffffffff8128f9ac>] seq_read+0x4c/0x3e0
[ 393.856004] #1: (rcu_read_lock){......}, at: [<ffffffff8172a005>] dev_seq_start+0x5/0x140
[ 393.856022]
stack backtrace:
[ 393.856032] CPU: 1 PID: 2642 Comm: ifconfig Not tainted 4.3.0-0.rc0.git9.1.fc24.x86_64 #1
...
[ 393.856072] Call Trace:
[ 393.856084] [<ffffffff8184b6c1>] dump_stack+0x4b/0x63
[ 393.856095] [<ffffffff81100d77>] lockdep_rcu_suspicious+0xd7/0x110
[ 393.856104] [<ffffffff810d5377>] ___might_sleep+0xa7/0x230
[ 393.856111] [<ffffffff810d5549>] __might_sleep+0x49/0x80
[ 393.856120] [<ffffffff811e575e>] __alloc_pages_nodemask+0x2fe/0xb90
[ 393.856129] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 393.856139] [<ffffffff81024b29>] ? sched_clock+0x9/0x10
[ 393.856146] [<ffffffff810e258c>] ? local_clock+0x1c/0x20
[ 393.856154] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 393.856164] [<ffffffff810218e6>] dma_generic_alloc_coherent+0x96/0x130
[ 393.856173] [<ffffffff81069865>] x86_swiotlb_alloc_coherent+0x25/0x50
[ 393.856240] [<ffffffff810215fd>] dma_alloc_attrs+0x6d/0xe0
[ 393.856256] [<ffffffffa003525e>] rtl8169_map_counters+0x3e/0x70 [r8169]
[ 393.856278] [<ffffffffa0036674>] rtl8169_update_counters+0x64/0x140 [r8169]
[ 393.856291] [<ffffffffa00368ff>] rtl8169_get_stats64+0xbf/0x130 [r8169]
[ 393.856307] [<ffffffff81700b74>] dev_get_stats+0x54/0x100
[ 393.856316] [<ffffffff817299a7>] dev_seq_printf_stats+0x37/0x120
[ 393.856327] [<ffffffff81729aa4>] dev_seq_show+0x14/0x30
[ 393.856334] [<ffffffff8128fc5a>] seq_read+0x2fa/0x3e0
[ 393.856345] [<ffffffff812df0c2>] proc_reg_read+0x42/0x70
[ 393.856358] [<ffffffff812663c7>] __vfs_read+0x37/0x100
[ 393.856368] [<ffffffff81388743>] ? security_file_permission+0xa3/0xc0
[ 393.856376] [<ffffffff81266d46>] vfs_read+0x86/0x130
[ 393.856384] [<ffffffff81267ac8>] SyS_read+0x58/0xd0
[ 393.856393] [<ffffffff81855372>] entry_SYSCALL_64_fastpath+0x12/0x76
[ 393.856402] BUG: sleeping function called from invalid context at mm/page_alloc.c:3186
[ 393.856408] in_atomic(): 1, irqs_disabled(): 0, pid: 2642, name: ifconfig
[ 393.856412] INFO: lockdep is turned off.
[ 393.856420] CPU: 1 PID: 2642 Comm: ifconfig Not tainted 4.3.0-0.rc0.git9.1.fc24.x86_64 #1
...
[ 393.856467] Call Trace:
[ 393.856476] [<ffffffff8184b6c1>] dump_stack+0x4b/0x63
[ 393.856484] [<ffffffff810d5449>] ___might_sleep+0x179/0x230
[ 393.856493] [<ffffffff810d5549>] __might_sleep+0x49/0x80
[ 393.856501] [<ffffffff811e575e>] __alloc_pages_nodemask+0x2fe/0xb90
[ 393.856513] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 393.856522] [<ffffffff81024b29>] ? sched_clock+0x9/0x10
[ 393.856529] [<ffffffff810e258c>] ? local_clock+0x1c/0x20
[ 393.856537] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 393.856547] [<ffffffff810218e6>] dma_generic_alloc_coherent+0x96/0x130
[ 393.856556] [<ffffffff81069865>] x86_swiotlb_alloc_coherent+0x25/0x50
[ 393.856564] [<ffffffff810215fd>] dma_alloc_attrs+0x6d/0xe0
[ 393.856577] [<ffffffffa003525e>] rtl8169_map_counters+0x3e/0x70 [r8169]
[ 393.856594] [<ffffffffa0036674>] rtl8169_update_counters+0x64/0x140 [r8169]
[ 393.856606] [<ffffffffa00368ff>] rtl8169_get_stats64+0xbf/0x130 [r8169]
[ 393.856615] [<ffffffff81700b74>] dev_get_stats+0x54/0x100
[ 393.856623] [<ffffffff817299a7>] dev_seq_printf_stats+0x37/0x120
[ 393.856635] [<ffffffff81729aa4>] dev_seq_show+0x14/0x30
[ 393.856643] [<ffffffff8128fc5a>] seq_read+0x2fa/0x3e0
[ 393.856657] [<ffffffff812df0c2>] proc_reg_read+0x42/0x70
[ 393.856665] [<ffffffff812663c7>] __vfs_read+0x37/0x100
[ 393.856673] [<ffffffff81388743>] ? security_file_permission+0xa3/0xc0
[ 393.856681] [<ffffffff81266d46>] vfs_read+0x86/0x130
[ 393.856688] [<ffffffff81267ac8>] SyS_read+0x58/0xd0
[ 393.856697] [<ffffffff81855372>] entry_SYSCALL_64_fastpath+0x12/0x76
[ 426.311398] BUG: sleeping function called from invalid context at mm/page_alloc.c:3186
[ 426.311412] in_atomic(): 1, irqs_disabled(): 0, pid: 2651, name: ifconfig
[ 426.311417] INFO: lockdep is turned off.
[ 426.311426] CPU: 3 PID: 2651 Comm: ifconfig Not tainted 4.3.0-0.rc0.git9.1.fc24.x86_64 #1
...
[ 426.311470] Call Trace:
[ 426.311486] [<ffffffff8184b6c1>] dump_stack+0x4b/0x63
[ 426.311497] [<ffffffff810d5449>] ___might_sleep+0x179/0x230
[ 426.311505] [<ffffffff810d5549>] __might_sleep+0x49/0x80
[ 426.311514] [<ffffffff811e575e>] __alloc_pages_nodemask+0x2fe/0xb90
[ 426.311524] [<ffffffff8142cf36>] ? debug_object_activate+0xb6/0x1e0
[ 426.311534] [<ffffffff8142d5c1>] ? debug_object_active_state+0x91/0x150
[ 426.311545] [<ffffffff810218e6>] dma_generic_alloc_coherent+0x96/0x130
[ 426.311555] [<ffffffff81069865>] x86_swiotlb_alloc_coherent+0x25/0x50
[ 426.311562] [<ffffffff810215fd>] dma_alloc_attrs+0x6d/0xe0
[ 426.311577] [<ffffffffa003525e>] rtl8169_map_counters+0x3e/0x70 [r8169]
[ 426.311589] [<ffffffffa0036674>] rtl8169_update_counters+0x64/0x140 [r8169]
[ 426.311601] [<ffffffffa00368ff>] rtl8169_get_stats64+0xbf/0x130 [r8169]
[ 426.311612] [<ffffffff81700b74>] dev_get_stats+0x54/0x100
[ 426.311620] [<ffffffff817299a7>] dev_seq_printf_stats+0x37/0x120
[ 426.311630] [<ffffffff81729aa4>] dev_seq_show+0x14/0x30
[ 426.311638] [<ffffffff8128fc5a>] seq_read+0x2fa/0x3e0
[ 426.311648] [<ffffffff812df0c2>] proc_reg_read+0x42/0x70
[ 426.311655] [<ffffffff812663c7>] __vfs_read+0x37/0x100
[ 426.311664] [<ffffffff81388743>] ? security_file_permission+0xa3/0xc0
[ 426.311672] [<ffffffff81266d46>] vfs_read+0x86/0x130
[ 426.311679] [<ffffffff81267ac8>] SyS_read+0x58/0xd0
[ 426.311687] [<ffffffff81855372>] entry_SYSCALL_64_fastpath+0x12/0x76
> If it has to be spanish, I'd prefer mujer, but whatever.
>
But whatever.
>>> It would also be interesting to see the "noise" as it looks after
>>> applying the above patch...
>>
>> The "noise" after applying "r8169: Fix sleeping function called during get_stats64":
>> [...]
>> [ 215.049067] Call Trace:
>> [ 215.049078] [<ffffffff8184b6c1>] dump_stack+0x4b/0x63
>> [ 215.049090] [<ffffffff81100d77>] lockdep_rcu_suspicious+0xd7/0x110
>> [ 215.049099] [<ffffffff810d5377>] ___might_sleep+0xa7/0x230
>> [ 215.049107] [<ffffffff810d5549>] __might_sleep+0x49/0x80
>> [ 215.049121] [<ffffffff811e575e>] __alloc_pages_nodemask+0x2fe/0xb90
>> [ 215.049130] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
>> [ 215.049141] [<ffffffff81024b29>] ? sched_clock+0x9/0x10
>> [ 215.049149] [<ffffffff810e258c>] ? local_clock+0x1c/0x20
>> [ 215.049157] [<ffffffff81121b0d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
>> [ 215.049168] [<ffffffff810218e6>] dma_generic_alloc_coherent+0x96/0x130
>> [ 215.049178] [<ffffffff81069865>] x86_swiotlb_alloc_coherent+0x25/0x50
>> [ 215.049193] [<ffffffff810215fd>] dma_alloc_attrs+0x6d/0xe0
>> [ 215.049208] [<ffffffffa002e25e>] rtl8169_map_counters+0x3e/0x70 [r8169]
>
> This is very certainly not the r8169.ko driver with my patch applied.
> There is no rtl8169_map_counters function anymore, just as with
> Francois' patch. I'm not sure what you're doing wrong there, but this
> stack dump definitely cannot be produced with either Francois or my
> patch, so you're apparently testing the unpatched upstream driver all
> the time.
>
$ modinfo -n r8169
/lib/modules/4.3.0-0.rc0.git9.1.fc24.x86_64/updates/r8169.ko
This one -patched- is used, right?
$ objdump -DS $(modinfo -n r8169) | grep rtl8169_map_counters ; echo $?
1
The one in "/lib/modules/$(uname -r)/updates/ has priority, right?
# unxz /lib/modules/4.3.0-0.rc0.git9.1.fc24.x86_64/kernel/drivers/net/ethernet/realtek/r8169.ko.xz
$ objdump -DS /lib/modules/4.3.0-0.rc0.git9.1.fc24.x86_64/kernel/drivers/net/ethernet/realtek/r8169.ko | grep rtl8169_map_counters
0000000000002220 <rtl8169_map_counters>:
2220: e8 00 00 00 00 callq 2225 <rtl8169_map_counters+0x5>
2259: e8 00 00 00 00 callq 225e <rtl8169_map_counters+0x3e>
2261: 74 19 je 227c <rtl8169_map_counters+0x5c>
366f: e8 ac eb ff ff callq 2220 <rtl8169_map_counters>
b44f: e8 cc 6d ff ff callq 2220 <rtl8169_map_counters>
And this is the original, which is not used, right?
>> ...
>> etc.
>> etc.
>> etc.
>>
>> This looks the same as at the beginning, as if you were dealing with
>> an entirely different problem, hombre.
>
> No, sorry, it's you running the wrong kernel module, and a single
> occurence of the stack dump would have been sufficient, but thanks
> all the same.
>
>
> Corinna
>
If you say so, hombre.
next prev parent reply other threads:[~2015-09-09 23:11 UTC|newest]
Thread overview: 24+ messages / expand[flat|nested] mbox.gz Atom feed top
2015-09-04 14:05 BUG: sleeping function called from invalid context at mm/page_alloc.c:3186 poma
2015-09-04 18:36 ` David Miller
2015-09-04 20:59 ` [PATCH net 1/1] r8169: fix sleepable allocation during netdevice stats retrieval Francois Romieu
2015-09-04 22:22 ` David Miller
2015-09-04 23:11 ` Francois Romieu
2015-09-04 23:15 ` David Miller
2015-09-06 10:19 ` Corinna Vinschen
2015-09-06 20:20 ` Francois Romieu
2015-09-07 7:13 ` poma
2015-09-07 8:50 ` Corinna Vinschen
2015-09-07 14:43 ` poma
2015-09-08 6:36 ` poma
2015-09-09 15:24 ` poma
2015-09-09 15:54 ` Corinna Vinschen
2015-09-09 15:55 ` Corinna Vinschen
2015-09-09 18:34 ` poma
2015-09-09 19:04 ` David Miller
2015-09-10 0:38 ` poma
2015-09-09 19:08 ` Corinna Vinschen
2015-09-09 23:11 ` poma [this message]
2015-09-09 23:51 ` poma
2015-09-10 8:47 ` Corinna Vinschen
2015-09-10 12:36 ` poma
2015-09-10 14:29 ` Corinna Vinschen
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=55F0BCB6.5030508@gmail.com \
--to=pomidorabelisima@gmail.com \
--cc=benedikt.meurer@unix-ag.uni-siegen.de \
--cc=bernhard.walle@gmx.de \
--cc=davem@davemloft.net \
--cc=frivoal@xfce.org \
--cc=hscholz@raisdorf.net \
--cc=m8t@gandi.net \
--cc=netdev@vger.kernel.org \
--cc=romieu@fr.zoreil.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.