[stabe-rc 5.9 ] sched: core.c:7270 Illegal context switch in RCU-bh read-side critical section!

Tue Dec 15 09:45:31 EST 2020

On Tue, Dec 15, 2020 at 07:50:31AM +0530, Naresh Kamboju wrote:
> There are two warnings "WARNING: suspicious RCU usage" noticed on arm64 juno-r2
> device while running selftest bpf test_tc_edt.sh and net: udpgro_bench.sh.
> These warnings are occurring intermittently.
> 
> metadata:
>   git branch: linux-5.9.y
>   git repo: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable-rc.git
>   git describe: v5.9.14-106-g609d95a95925
>   make_kernelversion: 5.9.15-rc1
>   kernel-config:
> http://snapshots.linaro.org/openembedded/lkft/lkft/sumo/juno/lkft/linux-stable-rc-5.9/58/config
> 
> 
> Steps to reproduce:
> ------------------
> Not easy to reproduce.
> 
> Crash log:
> --------------
> # selftests: bpf: test_tc_edt.sh
> [  503.796362]
> [  503.797960] =============================
> [  503.802131] WARNING: suspicious RCU usage
> [  503.806232] 5.9.15-rc1 #1 Tainted: G        W
> [  503.811358] -----------------------------
> [  503.815444] /usr/src/kernel/kernel/sched/core.c:7270 Illegal
> context switch in RCU-bh read-side critical section!
> [  503.825858]
> [  503.825858] other info that might help us debug this:
> [  503.825858]
> [  503.833998]
> [  503.833998] rcu_scheduler_active = 2, debug_locks = 1
> [  503.840981] 3 locks held by kworker/u12:1/157:
> [  503.845514]  #0: ffff0009754ed538
> ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work+0x208/0x768
> [  503.855048]  #1: ffff800013e63df0 (net_cleanup_work){+.+.}-{0:0},
> at: process_one_work+0x208/0x768
> [  503.864201]  #2: ffff8000129fe3f0 (pernet_ops_rwsem){++++}-{3:3},
> at: cleanup_net+0x64/0x3b8
> [  503.872786]
> [  503.872786] stack backtrace:
> [  503.877229] CPU: 1 PID: 157 Comm: kworker/u12:1 Tainted: G        W
>         5.9.15-rc1 #1
> [  503.885433] Hardware name: ARM Juno development board (r2) (DT)
> [  503.891382] Workqueue: netns cleanup_net
> [  503.895324] Call trace:
> [  503.897786]  dump_backtrace+0x0/0x1f8
> [  503.901464]  show_stack+0x2c/0x38
> [  503.904796]  dump_stack+0xec/0x158
> [  503.908215]  lockdep_rcu_suspicious+0xd4/0xf8
> [  503.912591]  ___might_sleep+0x1e4/0x208

You really are forbidden to invoke ___might_sleep() while in a BH-disable
region of code, whether due to rcu_read_lock_bh(), local_bh_disable(),
or whatever else.

I do see the cond_resched() in inet_twsk_purge(), but I don't immediately
see a BH-disable region of code.  Maybe someone more familiar with this
code would have some ideas.

Or you could place checks for being in a BH-disable further up in
the code.  Or build with CONFIG_DEBUG_INFO=y to allow more precise
interpretation of this stack trace.

							Thanx, Paul

> [  503.916444]  inet_twsk_purge+0x144/0x378
> [  503.920384]  tcpv6_net_exit_batch+0x20/0x28
> [  503.924585]  ops_exit_list.isra.10+0x78/0x88
> [  503.928872]  cleanup_net+0x248/0x3b8
> [  503.932462]  process_one_work+0x2b0/0x768
> [  503.936487]  worker_thread+0x48/0x498
> [  503.940166]  kthread+0x158/0x168
> [  503.943409]  ret_from_fork+0x10/0x1c
> [  504.165891] IPv6: ADDRCONF(NETDEV_CHANGE): veth_src: link becomes ready
> [  504.459624] audit: type=1334 audit(1607978673.070:40866):
> prog-id=20436 op=LOAD
> <>
> [  879.304684]
> [  879.306200] =============================
> [  879.310314] WARNING: suspicious RCU usage
> [  879.314420] 5.9.15-rc1 #1 Tainted: G        W
> [  879.319554] -----------------------------
> [  879.323644] /usr/src/kernel/kernel/sched/core.c:7270 Illegal
> context switch in RCU-sched read-side critical section!
> [  879.334259]
> [  879.334259] other info that might help us debug this:
> [  879.334259]
> [  879.342345]
> [  879.342345] rcu_scheduler_active = 2, debug_locks = 1
> [  879.348958] 3 locks held by kworker/u12:8/248:
> [  879.353483]  #0: ffff0009754ed538
> ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work+0x208/0x768
> [  879.362910]  #1: ffff800013bc3df0 (net_cleanup_work){+.+.}-{0:0},
> at: process_one_work+0x208/0x768
> [  879.371984]  #2: ffff8000129fe3f0 (pernet_ops_rwsem){++++}-{3:3},
> at: cleanup_net+0x64/0x3b8
> [  879.380540]
> [  879.380540] stack backtrace:
> [  879.384998] CPU: 1 PID: 248 Comm: kworker/u12:8 Tainted: G        W
>         5.9.15-rc1 #1
> [  879.393201] Hardware name: ARM Juno development board (r2) (DT)
> [  879.399147] Workqueue: netns cleanup_net
> [  879.403089] Call trace:
> [  879.405550]  dump_backtrace+0x0/0x1f8
> [  879.409228]  show_stack+0x2c/0x38
> [  879.412561]  dump_stack+0xec/0x158
> # ud[  879.415980]  lockdep_rcu_suspicious+0xd4/0xf8
> [  879.420691]  ___might_sleep+0x1ac/0x208
> p tx:     32 MB/s      546 calls/[  879.424570]
> nf_ct_iterate_cleanup+0x1b8/0x2d8 [nf_conntrack]
> s    546 msg/s[  879.433190]  nf_conntrack_cleanup_net_list+0x58/0x100
> [nf_conntrack]
> 
> [  879.440765]  nf_conntrack_pernet_exit+0xa8/0xb8 [nf_conntrack]
> [  879.446755]  ops_exit_list.isra.10+0x78/0x88
> [  879.451043]  cleanup_net+0x248/0x3b8
> [  879.454635]  process_one_work+0x2b0/0x768
> [  879.458661]  worker_thread+0x48/0x498
> [  879.462340]  kthread+0x158/0x168
> [  879.465584]  ret_from_fork+0x10/0x1c
> 
> 
> Reported-by: Naresh Kamboju <naresh.kamboju at linaro.org>
> 
> Full test log link,
> https://qa-reports.linaro.org/lkft/linux-stable-rc-linux-5.9.y/build/v5.9.14-106-g609d95a95925/testrun/3586574/suite/linux-log-parser/test/check-kernel-warning-2049484/log
> 
> 
> -- 
> Linaro LKFT
> https://lkft.linaro.org