[syzbot] [crypto?] inconsistent lock state in padata_do_parallel (2)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: 18737353cca0 Merge tag 'edac_urgent_for_v6.9_rc2' of git:/..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=15d605e5180000
kernel config: https://syzkaller.appspot.com/x/.config?x=f64ec427e98bccd7
dashboard link: https://syzkaller.appspot.com/bug?extid=0cb5bb0f4bf9e79db3b3
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image (non-bootable): https://storage.googleapis.com/syzbot-assets/7bc7510fe41f/non_bootable_disk-18737353.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/e9d064c31921/vmlinux-18737353.xz
kernel image: https://storage.googleapis.com/syzbot-assets/6d950d42963e/bzImage-18737353.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+0cb5bb...@syzkaller.appspotmail.com

================================
WARNING: inconsistent lock state
6.9.0-rc1-syzkaller-00379-g18737353cca0 #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor.3/9760 [HC0[0]:SC1[3]:HE1:SE0] takes:
ffffffff8dcbca58 (padata_works_lock){+.?.}-{2:2}, at: spin_lock include/linux/spinlock.h:351 [inline]
ffffffff8dcbca58 (padata_works_lock){+.?.}-{2:2}, at: padata_do_parallel+0x3af/0x9e0 kernel/padata.c:213
{SOFTIRQ-ON-W} state was registered at:
lock_acquire kernel/locking/lockdep.c:5754 [inline]
lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5719
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
padata_work_alloc_mt kernel/padata.c:109 [inline]
padata_do_multithreaded+0x213/0xad0 kernel/padata.c:507
gather_bootmem_prealloc mm/hugetlb.c:3478 [inline]
hugetlb_init+0x38b/0x1150 mm/hugetlb.c:4634
do_one_initcall+0x128/0x700 init/main.c:1238
do_initcall_level init/main.c:1300 [inline]
do_initcalls init/main.c:1316 [inline]
do_basic_setup init/main.c:1335 [inline]
kernel_init_freeable+0x69d/0xca0 init/main.c:1548
kernel_init+0x1c/0x2b0 init/main.c:1437
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:243
irq event stamp: 2347422
hardirqs last enabled at (2347422): [<ffffffff8ae18812>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
hardirqs last enabled at (2347422): [<ffffffff8ae18812>] _raw_spin_unlock_irqrestore+0x52/0x80 kernel/locking/spinlock.c:194
hardirqs last disabled at (2347421): [<ffffffff8ae18522>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (2347421): [<ffffffff8ae18522>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
softirqs last enabled at (2342856): [<ffffffff8ae1b6ba>] softirq_handle_end kernel/softirq.c:400 [inline]
softirqs last enabled at (2342856): [<ffffffff8ae1b6ba>] __do_softirq+0x5da/0x922 kernel/softirq.c:583
softirqs last disabled at (2347407): [<ffffffff8151d6f9>] invoke_softirq kernel/softirq.c:428 [inline]
softirqs last disabled at (2347407): [<ffffffff8151d6f9>] __irq_exit_rcu kernel/softirq.c:633 [inline]
softirqs last disabled at (2347407): [<ffffffff8151d6f9>] irq_exit_rcu+0xb9/0x120 kernel/softirq.c:645

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(padata_works_lock);
<Interrupt>
lock(padata_works_lock);

*** DEADLOCK ***

4 locks held by syz-executor.3/9760:
#0: ffff8880234280e0 (&type->s_umount_key#110){+.+.}-{3:3}, at: __super_lock fs/super.c:56 [inline]
#0: ffff8880234280e0 (&type->s_umount_key#110){+.+.}-{3:3}, at: __super_lock_excl fs/super.c:71 [inline]
#0: ffff8880234280e0 (&type->s_umount_key#110){+.+.}-{3:3}, at: deactivate_super+0xd6/0x100 fs/super.c:504
#1: ffffc900008f8cb0 ((&d->timer)){+.-.}-{0:0}, at: call_timer_fn+0x11a/0x610 kernel/time/timer.c:1790
#2: ffffffff8dbb1560 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:329 [inline]
#2: ffffffff8dbb1560 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:781 [inline]
#2: ffffffff8dbb1560 (rcu_read_lock){....}-{1:2}, at: tipc_bearer_xmit_skb+0xb8/0x430 net/tipc/bearer.c:564
#3: ffffffff8dbb1500 (rcu_read_lock_bh){....}-{1:2}, at: local_bh_disable include/linux/bottom_half.h:20 [inline]
#3: ffffffff8dbb1500 (rcu_read_lock_bh){....}-{1:2}, at: rcu_read_lock_bh include/linux/rcupdate.h:833 [inline]
#3: ffffffff8dbb1500 (rcu_read_lock_bh){....}-{1:2}, at: padata_do_parallel+0x42/0x9e0 kernel/padata.c:183

stack backtrace:
CPU: 3 PID: 9760 Comm: syz-executor.3 Not tainted 6.9.0-rc1-syzkaller-00379-g18737353cca0 #0
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:114
print_usage_bug kernel/locking/lockdep.c:3971 [inline]
valid_state kernel/locking/lockdep.c:4013 [inline]
mark_lock_irq kernel/locking/lockdep.c:4216 [inline]
mark_lock+0x923/0xc60 kernel/locking/lockdep.c:4678
mark_usage kernel/locking/lockdep.c:4567 [inline]
__lock_acquire+0x13d4/0x3b30 kernel/locking/lockdep.c:5091
lock_acquire kernel/locking/lockdep.c:5754 [inline]
lock_acquire+0x1b1/0x560 kernel/locking/lockdep.c:5719
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
padata_do_parallel+0x3af/0x9e0 kernel/padata.c:213
pcrypt_aead_encrypt+0x3a3/0x4f0 crypto/pcrypt.c:117
crypto_aead_encrypt+0xbe/0x100 crypto/aead.c:121
tipc_aead_encrypt net/tipc/crypto.c:821 [inline]
tipc_crypto_xmit+0xe3d/0x23e0 net/tipc/crypto.c:1756
tipc_bearer_xmit_skb+0x160/0x430 net/tipc/bearer.c:568
tipc_disc_timeout+0x5b3/0x850 net/tipc/discover.c:338
call_timer_fn+0x1a0/0x610 kernel/time/timer.c:1793
expire_timers kernel/time/timer.c:1844 [inline]
__run_timers+0x74b/0xaf0 kernel/time/timer.c:2418
__run_timer_base kernel/time/timer.c:2429 [inline]
__run_timer_base kernel/time/timer.c:2422 [inline]
run_timer_base+0x111/0x190 kernel/time/timer.c:2438
run_timer_softirq+0x1a/0x40 kernel/time/timer.c:2448
__do_softirq+0x218/0x922 kernel/softirq.c:554
invoke_softirq kernel/softirq.c:428 [inline]
__irq_exit_rcu kernel/softirq.c:633 [inline]
irq_exit_rcu+0xb9/0x120 kernel/softirq.c:645
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
sysvec_apic_timer_interrupt+0x95/0xb0 arch/x86/kernel/apic/apic.c:1043
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:__sanitizer_cov_trace_pc+0x33/0x60 kernel/kcov.c:207
Code: 65 76 7e 65 8b 05 25 65 76 7e a9 00 01 ff 00 48 8b 34 24 74 0f f6 c4 01 74 35 8b 82 14 16 00 00 85 c0 74 2b 8b 82 f0 15 00 00 <83> f8 02 75 20 48 8b 8a f8 15 00 00 8b 92 f4 15 00 00 48 8b 01 48
RSP: 0018:ffffc90003b9f5a0 EFLAGS: 00000246
RAX: 0000000000000000 RBX: 0000000000000001 RCX: ffffffff8134284f
RDX: ffff888027030000 RSI: ffffffff813427f9 RDI: 0000000000000005
RBP: ffffc90003b9f640 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000001 R12: ffffc90003b9f5b0
R13: ffffffff81793df0 R14: ffffc90003b9f670 R15: ffff888027030000
arch_stack_walk+0xb9/0x170 arch/x86/kernel/stacktrace.c:26
stack_trace_save+0x95/0xd0 kernel/stacktrace.c:122
kasan_save_stack+0x33/0x60 mm/kasan/common.c:47
kasan_save_track+0x14/0x30 mm/kasan/common.c:68
kasan_save_free_info+0x3b/0x60 mm/kasan/generic.c:579
poison_slab_object mm/kasan/common.c:240 [inline]
__kasan_slab_free+0x11d/0x1a0 mm/kasan/common.c:256
kasan_slab_free include/linux/kasan.h:184 [inline]
slab_free_hook mm/slub.c:2106 [inline]
slab_free mm/slub.c:4280 [inline]
kfree+0x129/0x390 mm/slub.c:4390
kvfree+0x47/0x50 mm/util.c:680
f2fs_destroy_node_manager+0x85a/0xc60 fs/f2fs/node.c:3408
f2fs_put_super+0x6c8/0xf60 fs/f2fs/super.c:1658
generic_shutdown_super+0x159/0x3d0 fs/super.c:641
kill_block_super+0x3b/0x90 fs/super.c:1693
kill_f2fs_super+0x2b4/0x440 fs/f2fs/super.c:4857
deactivate_locked_super+0xbe/0x1a0 fs/super.c:472
deactivate_super+0xde/0x100 fs/super.c:505
cleanup_mnt+0x222/0x450 fs/namespace.c:1267
task_work_run+0x14e/0x250 kernel/task_work.c:180
resume_user_mode_work include/linux/resume_user_mode.h:50 [inline]
exit_to_user_mode_loop kernel/entry/common.c:114 [inline]
exit_to_user_mode_prepare include/linux/entry-common.h:328 [inline]
__syscall_exit_to_user_mode_work kernel/entry/common.c:207 [inline]
syscall_exit_to_user_mode+0x275/0x2a0 kernel/entry/common.c:218
do_syscall_64+0xe2/0x260 arch/x86/entry/common.c:89
entry_SYSCALL_64_after_hwframe+0x72/0x7a
RIP: 0033:0x7feb5a67f0d7
Code: b0 ff ff ff f7 d8 64 89 01 48 83 c8 ff c3 0f 1f 44 00 00 31 f6 e9 09 00 00 00 66 0f 1f 84 00 00 00 00 00 b8 a6 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 01 c3 48 c7 c2 b0 ff ff ff f7 d8 64 89 02 b8
RSP: 002b:00007fff44da0148 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007feb5a67f0d7
RDX: 0000000000000000 RSI: 000000000000000a RDI: 00007fff44da0200
RBP: 00007fff44da0200 R08: 0000000000000000 R09: 0000000000000000
R10: 00000000ffffffff R11: 0000000000000246 R12: 00007fff44da12c0
R13: 00007feb5a6c93b9 R14: 00000000000340c5 R15: 000000000000000d
</TASK>
----------------
Code disassembly (best guess):
0: 65 76 7e gs jbe 0x81
3: 65 8b 05 25 65 76 7e mov %gs:0x7e766525(%rip),%eax # 0x7e76652f
a: a9 00 01 ff 00 test $0xff0100,%eax
f: 48 8b 34 24 mov (%rsp),%rsi
13: 74 0f je 0x24
15: f6 c4 01 test $0x1,%ah
18: 74 35 je 0x4f
1a: 8b 82 14 16 00 00 mov 0x1614(%rdx),%eax
20: 85 c0 test %eax,%eax
22: 74 2b je 0x4f
24: 8b 82 f0 15 00 00 mov 0x15f0(%rdx),%eax
* 2a: 83 f8 02 cmp $0x2,%eax <-- trapping instruction
2d: 75 20 jne 0x4f
2f: 48 8b 8a f8 15 00 00 mov 0x15f8(%rdx),%rcx
36: 8b 92 f4 15 00 00 mov 0x15f4(%rdx),%edx
3c: 48 8b 01 mov (%rcx),%rax
3f: 48 rex.W


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

[Herbert Xu]

On Mon, Apr 01, 2024 at 07:08:28AM -0700, syzbot wrote:
>
> syzbot found the following issue on:
>
> HEAD commit: 18737353cca0 Merge tag 'edac_urgent_for_v6.9_rc2' of git:/..
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=15d605e5180000
> kernel config: https://syzkaller.appspot.com/x/.config?x=f64ec427e98bccd7
> dashboard link: https://syzkaller.appspot.com/bug?extid=0cb5bb0f4bf9e79db3b3
> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40

Strictly speaking this can't happen because for the time being
padata_do_multithreaded cannot run at the same time as the old
padata which occurs in BH context.

But the simplest fix is to just disable BH:

---8<---
As the old padata code can execute in softirq context, disable
softirqs for the new padata_do_mutithreaded code too as otherwise
lockdep will get antsy.

Reported-by: syzbot+0cb5bb...@syzkaller.appspotmail.com
Signed-off-by: Herbert Xu <her...@gondor.apana.org.au>

diff --git a/kernel/padata.c b/kernel/padata.c
index e3f639ff1670..53f4bc912712 100644
--- a/kernel/padata.c
+++ b/kernel/padata.c
@@ -106,7 +106,7 @@ static int __init padata_work_alloc_mt(int nworks, void *data,
{
int i;

- spin_lock(&padata_works_lock);
+ spin_lock_bh(&padata_works_lock);
/* Start at 1 because the current task participates in the job. */
for (i = 1; i < nworks; ++i) {
struct padata_work *pw = padata_work_alloc();
@@ -116,7 +116,7 @@ static int __init padata_work_alloc_mt(int nworks, void *data,
padata_work_init(pw, padata_mt_helper, data, 0);
list_add(&pw->pw_list, head);
}
- spin_unlock(&padata_works_lock);
+ spin_unlock_bh(&padata_works_lock);

return i;
}
@@ -134,12 +134,12 @@ static void __init padata_works_free(struct list_head *works)
if (list_empty(works))
return;

- spin_lock(&padata_works_lock);
+ spin_lock_bh(&padata_works_lock);
list_for_each_entry_safe(cur, next, works, pw_list) {
list_del(&cur->pw_list);
padata_work_free(cur);
}
- spin_unlock(&padata_works_lock);
+ spin_unlock_bh(&padata_works_lock);
}

static void padata_parallel_worker(struct work_struct *parallel_work)
--
Email: Herbert Xu <her...@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

[Daniel Jordan]

On Wed, Apr 03, 2024 at 05:36:18PM +0800, Herbert Xu wrote:
> On Mon, Apr 01, 2024 at 07:08:28AM -0700, syzbot wrote:
> >
> > syzbot found the following issue on:
> >
> > HEAD commit: 18737353cca0 Merge tag 'edac_urgent_for_v6.9_rc2' of git:/..
> > git tree: upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=15d605e5180000
> > kernel config: https://syzkaller.appspot.com/x/.config?x=f64ec427e98bccd7
> > dashboard link: https://syzkaller.appspot.com/bug?extid=0cb5bb0f4bf9e79db3b3
> > compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
>
> Strictly speaking this can't happen because for the time being
> padata_do_multithreaded cannot run at the same time as the old
> padata which occurs in BH context.
>
> But the simplest fix is to just disable BH:
>
> ---8<---
> As the old padata code can execute in softirq context, disable
> softirqs for the new padata_do_mutithreaded code too as otherwise
> lockdep will get antsy.
>
> Reported-by: syzbot+0cb5bb...@syzkaller.appspotmail.com
> Signed-off-by: Herbert Xu <her...@gondor.apana.org.au>

Acked-by: Daniel Jordan <daniel....@oracle.com>