* BUG: Invalid wait context in bpf_sk_storage_free
@ 2020-08-04 11:21 Lorenz Bauer
2020-08-04 16:05 ` Martin KaFai Lau
0 siblings, 1 reply; 5+ messages in thread
From: Lorenz Bauer @ 2020-08-04 11:21 UTC (permalink / raw)
To: bpf, Alexei Starovoitov, Daniel Borkmann, Martin Lau
Hi list,
I just got this warning while running test progs on commit
21594c44083c375697d418729c4b2e4522cf9f70 in the #4/22
bpf_sk_storage_map test.
[ 38.775254] =============================
[ 38.775692] [ BUG: Invalid wait context ]
[ 38.776234] 5.8.0-rc6+ #35 Not tainted
[ 38.776699] -----------------------------
[ 38.777141] test_progs/254 is trying to lock:
[ 38.777650] ffff8881197f4450 (&krcp->lock){....}-{3:3}, at:
kfree_call_rcu+0x1a6/0x5b0
[ 38.778589] other info that might help us debug this:
[ 38.779155] context-{5:5}
[ 38.779476] 3 locks held by test_progs/254:
[ 38.779944] #0: ffff88810dc3f020
(&sb->s_type->i_mutex_key#6){+.+.}-{4:4}, at:
__sock_release+0x76/0x280
[ 38.780957] #1: ffffffff83d66840 (rcu_read_lock){....}-{1:3}, at:
bpf_sk_storage_free+0x0/0x2a0
[ 38.781878] #2: ffff88810b6940b8 (&sk_storage->lock){+...}-{2:2},
at: bpf_sk_storage_free+0xa3/0x2a0
[ 38.782812] stack backtrace:
[ 38.783115] CPU: 1 PID: 254 Comm: test_progs Not tainted 5.8.0-rc6+ #35
[ 38.783789] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
BIOS 1.13.0-1ubuntu1 04/01/2014
[ 38.784711] Call Trace:
[ 38.784976] dump_stack+0x9e/0xe0
[ 38.785429] __lock_acquire.cold+0x3a6/0x46c
[ 38.786025] ? register_lock_class+0x17a0/0x17a0
[ 38.786588] lock_acquire+0x1be/0x7e0
[ 38.787010] ? kfree_call_rcu+0x1a6/0x5b0
[ 38.787421] ? check_flags+0x60/0x60
[ 38.787790] ? mark_lock+0x12c/0x1470
[ 38.788179] ? check_chain_key+0x215/0x5a0
[ 38.788613] ? print_usage_bug+0x1f0/0x1f0
[ 38.789036] _raw_spin_lock+0x2c/0x70
[ 38.789415] ? kfree_call_rcu+0x1a6/0x5b0
[ 38.789829] kfree_call_rcu+0x1a6/0x5b0
[ 38.790239] __selem_unlink_sk+0x1eb/0x520
[ 38.790691] bpf_sk_storage_free+0x118/0x2a0
[ 38.791138] __sk_destruct+0xd3/0x4d0
[ 38.791525] inet_release+0xf4/0x220
[ 38.791939] __sock_release+0xc0/0x280
[ 38.792328] sock_close+0xf/0x20
[ 38.792676] __fput+0x29b/0x7b0
[ 38.793004] task_work_run+0xcc/0x170
[ 38.793429] __prepare_exit_to_usermode+0x1c6/0x1d0
[ 38.793948] do_syscall_64+0x62/0xa0
[ 38.794407] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 38.795004] RIP: 0033:0x7f73410e33d7
[ 38.795376] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00
00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 03 00 00
00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 f3 fb
ff ff
[ 38.797266] RSP: 002b:00007ffc86615fe8 EFLAGS: 00000246 ORIG_RAX:
0000000000000003
[ 38.798030] RAX: 0000000000000000 RBX: 00007ffc86616040 RCX: 00007f73410e33d7
[ 38.798755] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
[ 38.799488] RBP: 000055fa708beb60 R08: 0000000000000007 R09: 000000000000002c
[ 38.800241] R10: 000055fa6abd508d R11: 0000000000000246 R12: 000000000000000d
[ 38.801007] R13: 00007ffc86616034 R14: 000000000000000c R15: 000055fa708bcb30
Not sure if this is useful or not, a quick search in the mailing list
didn't bring anything up.
Best
Lorenz
--
Lorenz Bauer | Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK
www.cloudflare.com
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: BUG: Invalid wait context in bpf_sk_storage_free
2020-08-04 11:21 BUG: Invalid wait context in bpf_sk_storage_free Lorenz Bauer
@ 2020-08-04 16:05 ` Martin KaFai Lau
2020-08-04 16:45 ` Lorenz Bauer
0 siblings, 1 reply; 5+ messages in thread
From: Martin KaFai Lau @ 2020-08-04 16:05 UTC (permalink / raw)
To: Lorenz Bauer; +Cc: bpf, Alexei Starovoitov, Daniel Borkmann
On Tue, Aug 04, 2020 at 12:21:01PM +0100, Lorenz Bauer wrote:
> Hi list,
>
> I just got this warning while running test progs on commit
> 21594c44083c375697d418729c4b2e4522cf9f70 in the #4/22
> bpf_sk_storage_map test.
>
> [ 38.775254] =============================
> [ 38.775692] [ BUG: Invalid wait context ]
> [ 38.776234] 5.8.0-rc6+ #35 Not tainted
> [ 38.776699] -----------------------------
> [ 38.777141] test_progs/254 is trying to lock:
> [ 38.777650] ffff8881197f4450 (&krcp->lock){....}-{3:3}, at:
> kfree_call_rcu+0x1a6/0x5b0
> [ 38.778589] other info that might help us debug this:
> [ 38.779155] context-{5:5}
> [ 38.779476] 3 locks held by test_progs/254:
> [ 38.779944] #0: ffff88810dc3f020
> (&sb->s_type->i_mutex_key#6){+.+.}-{4:4}, at:
> __sock_release+0x76/0x280
> [ 38.780957] #1: ffffffff83d66840 (rcu_read_lock){....}-{1:3}, at:
> bpf_sk_storage_free+0x0/0x2a0
> [ 38.781878] #2: ffff88810b6940b8 (&sk_storage->lock){+...}-{2:2},
> at: bpf_sk_storage_free+0xa3/0x2a0
> [ 38.782812] stack backtrace:
> [ 38.783115] CPU: 1 PID: 254 Comm: test_progs Not tainted 5.8.0-rc6+ #35
> [ 38.783789] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> BIOS 1.13.0-1ubuntu1 04/01/2014
> [ 38.784711] Call Trace:
> [ 38.784976] dump_stack+0x9e/0xe0
> [ 38.785429] __lock_acquire.cold+0x3a6/0x46c
> [ 38.786025] ? register_lock_class+0x17a0/0x17a0
> [ 38.786588] lock_acquire+0x1be/0x7e0
> [ 38.787010] ? kfree_call_rcu+0x1a6/0x5b0
> [ 38.787421] ? check_flags+0x60/0x60
> [ 38.787790] ? mark_lock+0x12c/0x1470
> [ 38.788179] ? check_chain_key+0x215/0x5a0
> [ 38.788613] ? print_usage_bug+0x1f0/0x1f0
> [ 38.789036] _raw_spin_lock+0x2c/0x70
> [ 38.789415] ? kfree_call_rcu+0x1a6/0x5b0
> [ 38.789829] kfree_call_rcu+0x1a6/0x5b0
> [ 38.790239] __selem_unlink_sk+0x1eb/0x520
> [ 38.790691] bpf_sk_storage_free+0x118/0x2a0
> [ 38.791138] __sk_destruct+0xd3/0x4d0
> [ 38.791525] inet_release+0xf4/0x220
> [ 38.791939] __sock_release+0xc0/0x280
> [ 38.792328] sock_close+0xf/0x20
> [ 38.792676] __fput+0x29b/0x7b0
> [ 38.793004] task_work_run+0xcc/0x170
> [ 38.793429] __prepare_exit_to_usermode+0x1c6/0x1d0
> [ 38.793948] do_syscall_64+0x62/0xa0
> [ 38.794407] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> [ 38.795004] RIP: 0033:0x7f73410e33d7
> [ 38.795376] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00
> 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 03 00 00
> 00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 f3 fb
> ff ff
> [ 38.797266] RSP: 002b:00007ffc86615fe8 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000003
> [ 38.798030] RAX: 0000000000000000 RBX: 00007ffc86616040 RCX: 00007f73410e33d7
> [ 38.798755] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
> [ 38.799488] RBP: 000055fa708beb60 R08: 0000000000000007 R09: 000000000000002c
> [ 38.800241] R10: 000055fa6abd508d R11: 0000000000000246 R12: 000000000000000d
> [ 38.801007] R13: 00007ffc86616034 R14: 000000000000000c R15: 000055fa708bcb30
>
> Not sure if this is useful or not, a quick search in the mailing list
> didn't bring anything up.
I cannot reproduce after running test_progs -t bpf_iter/bpf_sk_storage_map in
a loop. Can you share you config?
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: BUG: Invalid wait context in bpf_sk_storage_free
2020-08-04 16:05 ` Martin KaFai Lau
@ 2020-08-04 16:45 ` Lorenz Bauer
2020-08-05 0:20 ` Martin KaFai Lau
0 siblings, 1 reply; 5+ messages in thread
From: Lorenz Bauer @ 2020-08-04 16:45 UTC (permalink / raw)
To: Martin KaFai Lau; +Cc: bpf, Alexei Starovoitov, Daniel Borkmann
On Tue, 4 Aug 2020 at 17:05, Martin KaFai Lau <kafai@fb.com> wrote:
>
> On Tue, Aug 04, 2020 at 12:21:01PM +0100, Lorenz Bauer wrote:
> > Hi list,
> >
> > I just got this warning while running test progs on commit
> > 21594c44083c375697d418729c4b2e4522cf9f70 in the #4/22
> > bpf_sk_storage_map test.
> >
> > [ 38.775254] =============================
> > [ 38.775692] [ BUG: Invalid wait context ]
> > [ 38.776234] 5.8.0-rc6+ #35 Not tainted
> > [ 38.776699] -----------------------------
> > [ 38.777141] test_progs/254 is trying to lock:
> > [ 38.777650] ffff8881197f4450 (&krcp->lock){....}-{3:3}, at:
> > kfree_call_rcu+0x1a6/0x5b0
> > [ 38.778589] other info that might help us debug this:
> > [ 38.779155] context-{5:5}
> > [ 38.779476] 3 locks held by test_progs/254:
> > [ 38.779944] #0: ffff88810dc3f020
> > (&sb->s_type->i_mutex_key#6){+.+.}-{4:4}, at:
> > __sock_release+0x76/0x280
> > [ 38.780957] #1: ffffffff83d66840 (rcu_read_lock){....}-{1:3}, at:
> > bpf_sk_storage_free+0x0/0x2a0
> > [ 38.781878] #2: ffff88810b6940b8 (&sk_storage->lock){+...}-{2:2},
> > at: bpf_sk_storage_free+0xa3/0x2a0
> > [ 38.782812] stack backtrace:
> > [ 38.783115] CPU: 1 PID: 254 Comm: test_progs Not tainted 5.8.0-rc6+ #35
> > [ 38.783789] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> > BIOS 1.13.0-1ubuntu1 04/01/2014
> > [ 38.784711] Call Trace:
> > [ 38.784976] dump_stack+0x9e/0xe0
> > [ 38.785429] __lock_acquire.cold+0x3a6/0x46c
> > [ 38.786025] ? register_lock_class+0x17a0/0x17a0
> > [ 38.786588] lock_acquire+0x1be/0x7e0
> > [ 38.787010] ? kfree_call_rcu+0x1a6/0x5b0
> > [ 38.787421] ? check_flags+0x60/0x60
> > [ 38.787790] ? mark_lock+0x12c/0x1470
> > [ 38.788179] ? check_chain_key+0x215/0x5a0
> > [ 38.788613] ? print_usage_bug+0x1f0/0x1f0
> > [ 38.789036] _raw_spin_lock+0x2c/0x70
> > [ 38.789415] ? kfree_call_rcu+0x1a6/0x5b0
> > [ 38.789829] kfree_call_rcu+0x1a6/0x5b0
> > [ 38.790239] __selem_unlink_sk+0x1eb/0x520
> > [ 38.790691] bpf_sk_storage_free+0x118/0x2a0
> > [ 38.791138] __sk_destruct+0xd3/0x4d0
> > [ 38.791525] inet_release+0xf4/0x220
> > [ 38.791939] __sock_release+0xc0/0x280
> > [ 38.792328] sock_close+0xf/0x20
> > [ 38.792676] __fput+0x29b/0x7b0
> > [ 38.793004] task_work_run+0xcc/0x170
> > [ 38.793429] __prepare_exit_to_usermode+0x1c6/0x1d0
> > [ 38.793948] do_syscall_64+0x62/0xa0
> > [ 38.794407] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> > [ 38.795004] RIP: 0033:0x7f73410e33d7
> > [ 38.795376] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00
> > 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 03 00 00
> > 00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 f3 fb
> > ff ff
> > [ 38.797266] RSP: 002b:00007ffc86615fe8 EFLAGS: 00000246 ORIG_RAX:
> > 0000000000000003
> > [ 38.798030] RAX: 0000000000000000 RBX: 00007ffc86616040 RCX: 00007f73410e33d7
> > [ 38.798755] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
> > [ 38.799488] RBP: 000055fa708beb60 R08: 0000000000000007 R09: 000000000000002c
> > [ 38.800241] R10: 000055fa6abd508d R11: 0000000000000246 R12: 000000000000000d
> > [ 38.801007] R13: 00007ffc86616034 R14: 000000000000000c R15: 000055fa708bcb30
> >
> > Not sure if this is useful or not, a quick search in the mailing list
> > didn't bring anything up.
> I cannot reproduce after running test_progs -t bpf_iter/bpf_sk_storage_map in
> a loop. Can you share you config?
Here you go: https://gist.github.com/lmb/0f19df936b296df34e4cb90dec6c3032
--
Lorenz Bauer | Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK
www.cloudflare.com
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: BUG: Invalid wait context in bpf_sk_storage_free
2020-08-04 16:45 ` Lorenz Bauer
@ 2020-08-05 0:20 ` Martin KaFai Lau
2020-08-05 8:19 ` Lorenz Bauer
0 siblings, 1 reply; 5+ messages in thread
From: Martin KaFai Lau @ 2020-08-05 0:20 UTC (permalink / raw)
To: Lorenz Bauer; +Cc: bpf, Alexei Starovoitov, Daniel Borkmann
On Tue, Aug 04, 2020 at 05:45:43PM +0100, Lorenz Bauer wrote:
> On Tue, 4 Aug 2020 at 17:05, Martin KaFai Lau <kafai@fb.com> wrote:
> >
> > On Tue, Aug 04, 2020 at 12:21:01PM +0100, Lorenz Bauer wrote:
> > > Hi list,
> > >
> > > I just got this warning while running test progs on commit
> > > 21594c44083c375697d418729c4b2e4522cf9f70 in the #4/22
> > > bpf_sk_storage_map test.
> > >
> > > [ 38.775254] =============================
> > > [ 38.775692] [ BUG: Invalid wait context ]
> > > [ 38.776234] 5.8.0-rc6+ #35 Not tainted
> > > [ 38.776699] -----------------------------
> > > [ 38.777141] test_progs/254 is trying to lock:
> > > [ 38.777650] ffff8881197f4450 (&krcp->lock){....}-{3:3}, at:
> > > kfree_call_rcu+0x1a6/0x5b0
> > > [ 38.778589] other info that might help us debug this:
> > > [ 38.779155] context-{5:5}
> > > [ 38.779476] 3 locks held by test_progs/254:
> > > [ 38.779944] #0: ffff88810dc3f020
> > > (&sb->s_type->i_mutex_key#6){+.+.}-{4:4}, at:
> > > __sock_release+0x76/0x280
> > > [ 38.780957] #1: ffffffff83d66840 (rcu_read_lock){....}-{1:3}, at:
> > > bpf_sk_storage_free+0x0/0x2a0
> > > [ 38.781878] #2: ffff88810b6940b8 (&sk_storage->lock){+...}-{2:2},
> > > at: bpf_sk_storage_free+0xa3/0x2a0
> > > [ 38.782812] stack backtrace:
> > > [ 38.783115] CPU: 1 PID: 254 Comm: test_progs Not tainted 5.8.0-rc6+ #35
> > > [ 38.783789] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> > > BIOS 1.13.0-1ubuntu1 04/01/2014
> > > [ 38.784711] Call Trace:
> > > [ 38.784976] dump_stack+0x9e/0xe0
> > > [ 38.785429] __lock_acquire.cold+0x3a6/0x46c
> > > [ 38.786025] ? register_lock_class+0x17a0/0x17a0
> > > [ 38.786588] lock_acquire+0x1be/0x7e0
> > > [ 38.787010] ? kfree_call_rcu+0x1a6/0x5b0
> > > [ 38.787421] ? check_flags+0x60/0x60
> > > [ 38.787790] ? mark_lock+0x12c/0x1470
> > > [ 38.788179] ? check_chain_key+0x215/0x5a0
> > > [ 38.788613] ? print_usage_bug+0x1f0/0x1f0
> > > [ 38.789036] _raw_spin_lock+0x2c/0x70
> > > [ 38.789415] ? kfree_call_rcu+0x1a6/0x5b0
> > > [ 38.789829] kfree_call_rcu+0x1a6/0x5b0
> > > [ 38.790239] __selem_unlink_sk+0x1eb/0x520
> > > [ 38.790691] bpf_sk_storage_free+0x118/0x2a0
> > > [ 38.791138] __sk_destruct+0xd3/0x4d0
> > > [ 38.791525] inet_release+0xf4/0x220
> > > [ 38.791939] __sock_release+0xc0/0x280
> > > [ 38.792328] sock_close+0xf/0x20
> > > [ 38.792676] __fput+0x29b/0x7b0
> > > [ 38.793004] task_work_run+0xcc/0x170
> > > [ 38.793429] __prepare_exit_to_usermode+0x1c6/0x1d0
> > > [ 38.793948] do_syscall_64+0x62/0xa0
> > > [ 38.794407] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> > > [ 38.795004] RIP: 0033:0x7f73410e33d7
> > > [ 38.795376] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00
> > > 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 03 00 00
> > > 00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 f3 fb
> > > ff ff
> > > [ 38.797266] RSP: 002b:00007ffc86615fe8 EFLAGS: 00000246 ORIG_RAX:
> > > 0000000000000003
> > > [ 38.798030] RAX: 0000000000000000 RBX: 00007ffc86616040 RCX: 00007f73410e33d7
> > > [ 38.798755] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
> > > [ 38.799488] RBP: 000055fa708beb60 R08: 0000000000000007 R09: 000000000000002c
> > > [ 38.800241] R10: 000055fa6abd508d R11: 0000000000000246 R12: 000000000000000d
> > > [ 38.801007] R13: 00007ffc86616034 R14: 000000000000000c R15: 000055fa708bcb30
> > >
> > > Not sure if this is useful or not, a quick search in the mailing list
> > > didn't bring anything up.
> > I cannot reproduce after running test_progs -t bpf_iter/bpf_sk_storage_map in
> > a loop. Can you share you config?
>
> Here you go: https://gist.github.com/lmb/0f19df936b296df34e4cb90dec6c3032
I can reproduce now. The splat is from the "CONFIG_PROVE_RAW_LOCK_NESTING=y"
in the posted config above:
config PROVE_RAW_LOCK_NESTING
bool "Enable raw_spinlock - spinlock nesting checks"
depends on PROVE_LOCKING
default n
help
Enable the raw_spinlock vs. spinlock nesting checks which ensure
that the lock nesting rules for PREEMPT_RT enabled kernels are
not violated.
NOTE: There are known nesting problems. So if you enable this
option expect lockdep splats until these problems have been fully
addressed which is work in progress. This config switch allows to
identify and analyze these problems. It will be removed and the
check permanentely enabled once the main issues have been fixed.
If unsure, select N.
There are known issues in kfree_rcu() in PREEMPT_RT. My understanding is
some of them are being worked on, e.g.
https://lore.kernel.org/lkml/20200624201226.21197-2-paulmck@kernel.org/
https://lore.kernel.org/lkml/20200803163029.1997-1-urezki@gmail.com/
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: BUG: Invalid wait context in bpf_sk_storage_free
2020-08-05 0:20 ` Martin KaFai Lau
@ 2020-08-05 8:19 ` Lorenz Bauer
0 siblings, 0 replies; 5+ messages in thread
From: Lorenz Bauer @ 2020-08-05 8:19 UTC (permalink / raw)
To: Martin KaFai Lau; +Cc: bpf, Alexei Starovoitov, Daniel Borkmann
On Wed, 5 Aug 2020 at 01:20, Martin KaFai Lau <kafai@fb.com> wrote:
>
> On Tue, Aug 04, 2020 at 05:45:43PM +0100, Lorenz Bauer wrote:
> > On Tue, 4 Aug 2020 at 17:05, Martin KaFai Lau <kafai@fb.com> wrote:
> > >
> > > On Tue, Aug 04, 2020 at 12:21:01PM +0100, Lorenz Bauer wrote:
> > > > Hi list,
> > > >
> > > > I just got this warning while running test progs on commit
> > > > 21594c44083c375697d418729c4b2e4522cf9f70 in the #4/22
> > > > bpf_sk_storage_map test.
> > > >
> > > > [ 38.775254] =============================
> > > > [ 38.775692] [ BUG: Invalid wait context ]
> > > > [ 38.776234] 5.8.0-rc6+ #35 Not tainted
> > > > [ 38.776699] -----------------------------
> > > > [ 38.777141] test_progs/254 is trying to lock:
> > > > [ 38.777650] ffff8881197f4450 (&krcp->lock){....}-{3:3}, at:
> > > > kfree_call_rcu+0x1a6/0x5b0
> > > > [ 38.778589] other info that might help us debug this:
> > > > [ 38.779155] context-{5:5}
> > > > [ 38.779476] 3 locks held by test_progs/254:
> > > > [ 38.779944] #0: ffff88810dc3f020
> > > > (&sb->s_type->i_mutex_key#6){+.+.}-{4:4}, at:
> > > > __sock_release+0x76/0x280
> > > > [ 38.780957] #1: ffffffff83d66840 (rcu_read_lock){....}-{1:3}, at:
> > > > bpf_sk_storage_free+0x0/0x2a0
> > > > [ 38.781878] #2: ffff88810b6940b8 (&sk_storage->lock){+...}-{2:2},
> > > > at: bpf_sk_storage_free+0xa3/0x2a0
> > > > [ 38.782812] stack backtrace:
> > > > [ 38.783115] CPU: 1 PID: 254 Comm: test_progs Not tainted 5.8.0-rc6+ #35
> > > > [ 38.783789] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996),
> > > > BIOS 1.13.0-1ubuntu1 04/01/2014
> > > > [ 38.784711] Call Trace:
> > > > [ 38.784976] dump_stack+0x9e/0xe0
> > > > [ 38.785429] __lock_acquire.cold+0x3a6/0x46c
> > > > [ 38.786025] ? register_lock_class+0x17a0/0x17a0
> > > > [ 38.786588] lock_acquire+0x1be/0x7e0
> > > > [ 38.787010] ? kfree_call_rcu+0x1a6/0x5b0
> > > > [ 38.787421] ? check_flags+0x60/0x60
> > > > [ 38.787790] ? mark_lock+0x12c/0x1470
> > > > [ 38.788179] ? check_chain_key+0x215/0x5a0
> > > > [ 38.788613] ? print_usage_bug+0x1f0/0x1f0
> > > > [ 38.789036] _raw_spin_lock+0x2c/0x70
> > > > [ 38.789415] ? kfree_call_rcu+0x1a6/0x5b0
> > > > [ 38.789829] kfree_call_rcu+0x1a6/0x5b0
> > > > [ 38.790239] __selem_unlink_sk+0x1eb/0x520
> > > > [ 38.790691] bpf_sk_storage_free+0x118/0x2a0
> > > > [ 38.791138] __sk_destruct+0xd3/0x4d0
> > > > [ 38.791525] inet_release+0xf4/0x220
> > > > [ 38.791939] __sock_release+0xc0/0x280
> > > > [ 38.792328] sock_close+0xf/0x20
> > > > [ 38.792676] __fput+0x29b/0x7b0
> > > > [ 38.793004] task_work_run+0xcc/0x170
> > > > [ 38.793429] __prepare_exit_to_usermode+0x1c6/0x1d0
> > > > [ 38.793948] do_syscall_64+0x62/0xa0
> > > > [ 38.794407] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> > > > [ 38.795004] RIP: 0033:0x7f73410e33d7
> > > > [ 38.795376] Code: 64 89 02 48 c7 c0 ff ff ff ff eb bb 0f 1f 80 00
> > > > 00 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 03 00 00
> > > > 00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 f3 fb
> > > > ff ff
> > > > [ 38.797266] RSP: 002b:00007ffc86615fe8 EFLAGS: 00000246 ORIG_RAX:
> > > > 0000000000000003
> > > > [ 38.798030] RAX: 0000000000000000 RBX: 00007ffc86616040 RCX: 00007f73410e33d7
> > > > [ 38.798755] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000008
> > > > [ 38.799488] RBP: 000055fa708beb60 R08: 0000000000000007 R09: 000000000000002c
> > > > [ 38.800241] R10: 000055fa6abd508d R11: 0000000000000246 R12: 000000000000000d
> > > > [ 38.801007] R13: 00007ffc86616034 R14: 000000000000000c R15: 000055fa708bcb30
> > > >
> > > > Not sure if this is useful or not, a quick search in the mailing list
> > > > didn't bring anything up.
> > > I cannot reproduce after running test_progs -t bpf_iter/bpf_sk_storage_map in
> > > a loop. Can you share you config?
> >
> > Here you go: https://gist.github.com/lmb/0f19df936b296df34e4cb90dec6c3032
> I can reproduce now. The splat is from the "CONFIG_PROVE_RAW_LOCK_NESTING=y"
> in the posted config above:
>
> config PROVE_RAW_LOCK_NESTING
> bool "Enable raw_spinlock - spinlock nesting checks"
> depends on PROVE_LOCKING
> default n
> help
> Enable the raw_spinlock vs. spinlock nesting checks which ensure
> that the lock nesting rules for PREEMPT_RT enabled kernels are
> not violated.
>
> NOTE: There are known nesting problems. So if you enable this
> option expect lockdep splats until these problems have been fully
> addressed which is work in progress. This config switch allows to
> identify and analyze these problems. It will be removed and the
> check permanentely enabled once the main issues have been fixed.
>
> If unsure, select N.
>
> There are known issues in kfree_rcu() in PREEMPT_RT. My understanding is
> some of them are being worked on, e.g.
> https://lore.kernel.org/lkml/20200624201226.21197-2-paulmck@kernel.org/
> https://lore.kernel.org/lkml/20200803163029.1997-1-urezki@gmail.com/
Thanks for taking a look, I'll disable this for now then!
--
Lorenz Bauer | Systems Engineer
6th Floor, County Hall/The Riverside Building, SE1 7PB, UK
www.cloudflare.com
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2020-08-05 8:19 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-08-04 11:21 BUG: Invalid wait context in bpf_sk_storage_free Lorenz Bauer
2020-08-04 16:05 ` Martin KaFai Lau
2020-08-04 16:45 ` Lorenz Bauer
2020-08-05 0:20 ` Martin KaFai Lau
2020-08-05 8:19 ` Lorenz Bauer
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.