* inconsistent lock state in ima_process_queued_keys
@ 2020-01-14 13:56 syzbot
2020-01-14 13:58 ` Dmitry Vyukov
2020-01-18 3:14 ` syzbot
0 siblings, 2 replies; 8+ messages in thread
From: syzbot @ 2020-01-14 13:56 UTC (permalink / raw)
To: dmitry.kasatkin, jmorris, linux-integrity, linux-kernel,
linux-security-module, serge, syzkaller-bugs, zohar
Hello,
syzbot found the following crash on:
HEAD commit: 1b851f98 Add linux-next specific files for 20200114
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=12bcbb25e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=3e7d9cf7ebfa08ad
dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
Unfortunately, I don't have any reproducer for this crash yet.
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
================================
WARNING: inconsistent lock state
5.5.0-rc6-next-20200114-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
syz-executor.5/9563 [HC0[0]:SC1[1]:HE1:SE0] takes:
ffffffff8a03aa18 (ima_keys_lock){+.?.}, at: spin_lock
include/linux/spinlock.h:338 [inline]
ffffffff8a03aa18 (ima_keys_lock){+.?.}, at:
ima_process_queued_keys+0x4f/0x320
security/integrity/ima/ima_asymmetric_keys.c:144
{SOFTIRQ-ON-W} state was registered at:
lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:338 [inline]
ima_queue_key security/integrity/ima/ima_asymmetric_keys.c:111 [inline]
ima_post_key_create_or_update+0x234/0x470
security/integrity/ima/ima_asymmetric_keys.c:194
key_create_or_update+0x6b8/0xcb0 security/keys/key.c:944
load_system_certificate_list+0x1ba/0x25e certs/system_keyring.c:161
do_one_initcall+0x120/0x820 init/main.c:940
do_initcall_level init/main.c:1014 [inline]
do_initcalls init/main.c:1022 [inline]
do_basic_setup init/main.c:1039 [inline]
kernel_init_freeable+0x4ca/0x570 init/main.c:1223
kernel_init+0x12/0x1bf init/main.c:1130
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
irq event stamp: 319180
hardirqs last enabled at (319180): [<ffffffff87ec3333>]
__raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (319180): [<ffffffff87ec3333>]
_raw_spin_unlock_irq+0x23/0x80 kernel/locking/spinlock.c:199
hardirqs last disabled at (319179): [<ffffffff87ec351a>]
__raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (319179): [<ffffffff87ec351a>]
_raw_spin_lock_irq+0x3a/0x80 kernel/locking/spinlock.c:167
softirqs last enabled at (316932): [<ffffffff882006cd>]
__do_softirq+0x6cd/0x98c kernel/softirq.c:319
softirqs last disabled at (319177): [<ffffffff8147800b>] invoke_softirq
kernel/softirq.c:373 [inline]
softirqs last disabled at (319177): [<ffffffff8147800b>]
irq_exit+0x19b/0x1e0 kernel/softirq.c:413
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(ima_keys_lock);
<Interrupt>
lock(ima_keys_lock);
*** DEADLOCK ***
1 lock held by syz-executor.5/9563:
#0: ffffc90000007d50 ((&ima_key_queue_timer)){+.-.}, at: lockdep_copy_map
include/linux/lockdep.h:172 [inline]
#0: ffffc90000007d50 ((&ima_key_queue_timer)){+.-.}, at:
call_timer_fn+0xe0/0x780 kernel/time/timer.c:1394
stack backtrace:
CPU: 0 PID: 9563 Comm: syz-executor.5 Not tainted
5.5.0-rc6-next-20200114-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x197/0x210 lib/dump_stack.c:118
print_usage_bug.cold+0x327/0x378 kernel/locking/lockdep.c:3100
valid_state kernel/locking/lockdep.c:3111 [inline]
mark_lock_irq kernel/locking/lockdep.c:3308 [inline]
mark_lock+0xbb4/0x1220 kernel/locking/lockdep.c:3665
mark_usage kernel/locking/lockdep.c:3565 [inline]
__lock_acquire+0x1e8e/0x4a00 kernel/locking/lockdep.c:3908
lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:338 [inline]
ima_process_queued_keys+0x4f/0x320
security/integrity/ima/ima_asymmetric_keys.c:144
ima_timer_handler+0x15/0x20 security/integrity/ima/ima_asymmetric_keys.c:46
call_timer_fn+0x1ac/0x780 kernel/time/timer.c:1404
expire_timers kernel/time/timer.c:1449 [inline]
__run_timers kernel/time/timer.c:1773 [inline]
__run_timers kernel/time/timer.c:1740 [inline]
run_timer_softirq+0x6c3/0x1790 kernel/time/timer.c:1786
__do_softirq+0x262/0x98c kernel/softirq.c:292
invoke_softirq kernel/softirq.c:373 [inline]
irq_exit+0x19b/0x1e0 kernel/softirq.c:413
exiting_irq arch/x86/include/asm/apic.h:536 [inline]
smp_apic_timer_interrupt+0x1a3/0x610 arch/x86/kernel/apic/apic.c:1137
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:752
[inline]
RIP: 0010:slab_alloc mm/slab.c:3313 [inline]
RIP: 0010:kmem_cache_alloc+0x283/0x710 mm/slab.c:3484
Code: 7e 0f 85 dc fe ff ff e8 0c 3f 4d ff e9 d2 fe ff ff e8 31 aa c7 ff 48
83 3d 21 84 00 08 00 0f 84 51 03 00 00 48 8b 7d d0 57 9d <0f> 1f 44 00 00
e9 68 fe ff ff 31 d2 be 35 02 00 00 48 c7 c7 2e a1
RSP: 0018:ffffc9000641fd18 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000007 RBX: 0000000000000cc0 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000006 RDI: 0000000000000286
RBP: ffffc9000641fd80 R08: ffff8880543b22c0 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aa5f8a80
R13: ffff8880aa5f8a80 R14: 0000000000000cc0 R15: ffff8880a8916600
getname_flags fs/namei.c:138 [inline]
getname_flags+0xd6/0x5b0 fs/namei.c:128
getname fs/namei.c:209 [inline]
user_path_mountpoint_at+0x29/0x50 fs/namei.c:2820
ksys_umount+0x164/0xef0 fs/namespace.c:1683
__do_sys_umount fs/namespace.c:1709 [inline]
__se_sys_umount fs/namespace.c:1707 [inline]
__x64_sys_umount+0x54/0x80 fs/namespace.c:1707
do_syscall_64+0xfa/0x790 arch/x86/entry/common.c:294
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45d977
Code: 64 89 04 25 d0 02 00 00 58 5f ff d0 48 89 c7 e8 2f be ff ff 66 2e 0f
1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 a6 00 00 00 0f 05 <48> 3d 01 f0 ff
ff 0f 83 4d 8c fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffeff269038 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
RAX: ffffffffffffffda RBX: 000000000004d5f3 RCX: 000000000045d977
RDX: 000000000000000c RSI: 0000000000000002 RDI: 00007ffeff26a170
RBP: 000000000000003c R08: 0000000000000001 R09: 0000000001dc6940
R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffeff26a170
R13: 00007ffeff26a160 R14: 0000000000000000 R15: 00007ffeff26a170
---
This bug 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 syzkaller@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 13:56 inconsistent lock state in ima_process_queued_keys syzbot
@ 2020-01-14 13:58 ` Dmitry Vyukov
2020-01-14 14:56 ` Mimi Zohar
2020-01-18 3:14 ` syzbot
1 sibling, 1 reply; 8+ messages in thread
From: Dmitry Vyukov @ 2020-01-14 13:58 UTC (permalink / raw)
To: syzbot, Lakshmi Ramasubramanian
Cc: Dmitry Kasatkin, James Morris, linux-integrity, LKML,
linux-security-module, Serge E. Hallyn, syzkaller-bugs,
Mimi Zohar
On Tue, Jan 14, 2020 at 2:56 PM syzbot
<syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following crash on:
>
> HEAD commit: 1b851f98 Add linux-next specific files for 20200114
> git tree: linux-next
> console output: https://syzkaller.appspot.com/x/log.txt?x=12bcbb25e00000
> kernel config: https://syzkaller.appspot.com/x/.config?x=3e7d9cf7ebfa08ad
> dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
> compiler: gcc (GCC) 9.0.0 20181231 (experimental)
>
> Unfortunately, I don't have any reproducer for this crash yet.
>
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
+Lakshmi, you seem to have submitted a number of changes to this file recently.
This completely breaks linux-next testing for us, every kernel crashes
a few minutes after boot.
2020/01/14 14:45:00 vm-26: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:00 vm-12: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:01 vm-3: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:02 vm-8: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:03 vm-25: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:04 vm-27: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:04 VMs 0, executed 214279, cover 10140, crashes 5, repro 0
2020/01/14 14:45:05 vm-14: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:05 vm-11: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:06 vm-10: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:07 vm-0: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:08 vm-24: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:09 vm-2: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:10 vm-20: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:11 vm-7: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:12 vm-28: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:12 vm-1: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:13 vm-6: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:14 vm-4: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:14 VMs 0, executed 214279, cover 10140, crashes 17, repro 0
2020/01/14 14:45:15 vm-17: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:16 vm-16: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:16 vm-19: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:17 vm-15: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:18 vm-29: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:19 vm-21: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:20 vm-23: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:20 vm-13: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:21 vm-9: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:22 vm-5: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:23 vm-22: crash: inconsistent lock state in
ima_process_queued_keys
2020/01/14 14:45:24 VMs 0, executed 214279, cover 10140, crashes 28, repro 0
2020/01/14 14:45:24 vm-18: crash: inconsistent lock state in
ima_process_queued_keys
> ================================
> WARNING: inconsistent lock state
> 5.5.0-rc6-next-20200114-syzkaller #0 Not tainted
> --------------------------------
> inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
> syz-executor.5/9563 [HC0[0]:SC1[1]:HE1:SE0] takes:
> ffffffff8a03aa18 (ima_keys_lock){+.?.}, at: spin_lock
> include/linux/spinlock.h:338 [inline]
> ffffffff8a03aa18 (ima_keys_lock){+.?.}, at:
> ima_process_queued_keys+0x4f/0x320
> security/integrity/ima/ima_asymmetric_keys.c:144
> {SOFTIRQ-ON-W} state was registered at:
> lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
> __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
> _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
> spin_lock include/linux/spinlock.h:338 [inline]
> ima_queue_key security/integrity/ima/ima_asymmetric_keys.c:111 [inline]
> ima_post_key_create_or_update+0x234/0x470
> security/integrity/ima/ima_asymmetric_keys.c:194
> key_create_or_update+0x6b8/0xcb0 security/keys/key.c:944
> load_system_certificate_list+0x1ba/0x25e certs/system_keyring.c:161
> do_one_initcall+0x120/0x820 init/main.c:940
> do_initcall_level init/main.c:1014 [inline]
> do_initcalls init/main.c:1022 [inline]
> do_basic_setup init/main.c:1039 [inline]
> kernel_init_freeable+0x4ca/0x570 init/main.c:1223
> kernel_init+0x12/0x1bf init/main.c:1130
> ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
> irq event stamp: 319180
> hardirqs last enabled at (319180): [<ffffffff87ec3333>]
> __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
> hardirqs last enabled at (319180): [<ffffffff87ec3333>]
> _raw_spin_unlock_irq+0x23/0x80 kernel/locking/spinlock.c:199
> hardirqs last disabled at (319179): [<ffffffff87ec351a>]
> __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
> hardirqs last disabled at (319179): [<ffffffff87ec351a>]
> _raw_spin_lock_irq+0x3a/0x80 kernel/locking/spinlock.c:167
> softirqs last enabled at (316932): [<ffffffff882006cd>]
> __do_softirq+0x6cd/0x98c kernel/softirq.c:319
> softirqs last disabled at (319177): [<ffffffff8147800b>] invoke_softirq
> kernel/softirq.c:373 [inline]
> softirqs last disabled at (319177): [<ffffffff8147800b>]
> irq_exit+0x19b/0x1e0 kernel/softirq.c:413
>
> other info that might help us debug this:
> Possible unsafe locking scenario:
>
> CPU0
> ----
> lock(ima_keys_lock);
> <Interrupt>
> lock(ima_keys_lock);
>
> *** DEADLOCK ***
>
> 1 lock held by syz-executor.5/9563:
> #0: ffffc90000007d50 ((&ima_key_queue_timer)){+.-.}, at: lockdep_copy_map
> include/linux/lockdep.h:172 [inline]
> #0: ffffc90000007d50 ((&ima_key_queue_timer)){+.-.}, at:
> call_timer_fn+0xe0/0x780 kernel/time/timer.c:1394
>
> stack backtrace:
> CPU: 0 PID: 9563 Comm: syz-executor.5 Not tainted
> 5.5.0-rc6-next-20200114-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
> Google 01/01/2011
> Call Trace:
> <IRQ>
> __dump_stack lib/dump_stack.c:77 [inline]
> dump_stack+0x197/0x210 lib/dump_stack.c:118
> print_usage_bug.cold+0x327/0x378 kernel/locking/lockdep.c:3100
> valid_state kernel/locking/lockdep.c:3111 [inline]
> mark_lock_irq kernel/locking/lockdep.c:3308 [inline]
> mark_lock+0xbb4/0x1220 kernel/locking/lockdep.c:3665
> mark_usage kernel/locking/lockdep.c:3565 [inline]
> __lock_acquire+0x1e8e/0x4a00 kernel/locking/lockdep.c:3908
> lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
> __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
> _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
> spin_lock include/linux/spinlock.h:338 [inline]
> ima_process_queued_keys+0x4f/0x320
> security/integrity/ima/ima_asymmetric_keys.c:144
> ima_timer_handler+0x15/0x20 security/integrity/ima/ima_asymmetric_keys.c:46
> call_timer_fn+0x1ac/0x780 kernel/time/timer.c:1404
> expire_timers kernel/time/timer.c:1449 [inline]
> __run_timers kernel/time/timer.c:1773 [inline]
> __run_timers kernel/time/timer.c:1740 [inline]
> run_timer_softirq+0x6c3/0x1790 kernel/time/timer.c:1786
> __do_softirq+0x262/0x98c kernel/softirq.c:292
> invoke_softirq kernel/softirq.c:373 [inline]
> irq_exit+0x19b/0x1e0 kernel/softirq.c:413
> exiting_irq arch/x86/include/asm/apic.h:536 [inline]
> smp_apic_timer_interrupt+0x1a3/0x610 arch/x86/kernel/apic/apic.c:1137
> apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
> </IRQ>
> RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:752
> [inline]
> RIP: 0010:slab_alloc mm/slab.c:3313 [inline]
> RIP: 0010:kmem_cache_alloc+0x283/0x710 mm/slab.c:3484
> Code: 7e 0f 85 dc fe ff ff e8 0c 3f 4d ff e9 d2 fe ff ff e8 31 aa c7 ff 48
> 83 3d 21 84 00 08 00 0f 84 51 03 00 00 48 8b 7d d0 57 9d <0f> 1f 44 00 00
> e9 68 fe ff ff 31 d2 be 35 02 00 00 48 c7 c7 2e a1
> RSP: 0018:ffffc9000641fd18 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
> RAX: 0000000000000007 RBX: 0000000000000cc0 RCX: 0000000000000000
> RDX: 0000000000000000 RSI: 0000000000000006 RDI: 0000000000000286
> RBP: ffffc9000641fd80 R08: ffff8880543b22c0 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000000 R12: ffff8880aa5f8a80
> R13: ffff8880aa5f8a80 R14: 0000000000000cc0 R15: ffff8880a8916600
> getname_flags fs/namei.c:138 [inline]
> getname_flags+0xd6/0x5b0 fs/namei.c:128
> getname fs/namei.c:209 [inline]
> user_path_mountpoint_at+0x29/0x50 fs/namei.c:2820
> ksys_umount+0x164/0xef0 fs/namespace.c:1683
> __do_sys_umount fs/namespace.c:1709 [inline]
> __se_sys_umount fs/namespace.c:1707 [inline]
> __x64_sys_umount+0x54/0x80 fs/namespace.c:1707
> do_syscall_64+0xfa/0x790 arch/x86/entry/common.c:294
> entry_SYSCALL_64_after_hwframe+0x49/0xbe
> RIP: 0033:0x45d977
> Code: 64 89 04 25 d0 02 00 00 58 5f ff d0 48 89 c7 e8 2f be ff ff 66 2e 0f
> 1f 84 00 00 00 00 00 0f 1f 44 00 00 b8 a6 00 00 00 0f 05 <48> 3d 01 f0 ff
> ff 0f 83 4d 8c fb ff c3 66 2e 0f 1f 84 00 00 00 00
> RSP: 002b:00007ffeff269038 EFLAGS: 00000246 ORIG_RAX: 00000000000000a6
> RAX: ffffffffffffffda RBX: 000000000004d5f3 RCX: 000000000045d977
> RDX: 000000000000000c RSI: 0000000000000002 RDI: 00007ffeff26a170
> RBP: 000000000000003c R08: 0000000000000001 R09: 0000000001dc6940
> R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffeff26a170
> R13: 00007ffeff26a160 R14: 0000000000000000 R15: 00007ffeff26a170
>
>
> ---
> This bug 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 syzkaller@googlegroups.com.
>
> syzbot will keep track of this bug report. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/000000000000486474059c19f4d7%40google.com.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 13:58 ` Dmitry Vyukov
@ 2020-01-14 14:56 ` Mimi Zohar
2020-01-14 15:21 ` Dmitry Vyukov
0 siblings, 1 reply; 8+ messages in thread
From: Mimi Zohar @ 2020-01-14 14:56 UTC (permalink / raw)
To: Dmitry Vyukov, syzbot, Lakshmi Ramasubramanian
Cc: Dmitry Kasatkin, James Morris, linux-integrity, LKML,
linux-security-module, Serge E. Hallyn, syzkaller-bugs
On Tue, 2020-01-14 at 14:58 +0100, Dmitry Vyukov wrote:
> On Tue, Jan 14, 2020 at 2:56 PM syzbot
> <syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com> wrote:
> >
> > Hello,
> >
> > syzbot found the following crash on:
> >
> > HEAD commit: 1b851f98 Add linux-next specific files for 20200114
> > git tree: linux-next
> > console output: https://syzkaller.appspot.com/x/log.txt?x=12bcbb25e00000
> > kernel config: https://syzkaller.appspot.com/x/.config?x=3e7d9cf7ebfa08ad
> > dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
> > compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> >
> > Unfortunately, I don't have any reproducer for this crash yet.
> >
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
>
> +Lakshmi, you seem to have submitted a number of changes to this file recently.
>
> This completely breaks linux-next testing for us, every kernel crashes
> a few minutes after boot.
>
> 2020/01/14 14:45:00 vm-26: crash: inconsistent lock state in
> ima_process_queued_keys
Yikes! Are you running with an IMA policy? I assume this is being
caused by commit 8f5d2d06f217 ("IMA: Defined timer to free queued
keys". Does reverting it prevent this from happening?
Mimi
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 14:56 ` Mimi Zohar
@ 2020-01-14 15:21 ` Dmitry Vyukov
2020-01-14 16:54 ` Lakshmi Ramasubramanian
2020-01-14 17:19 ` Lakshmi Ramasubramanian
0 siblings, 2 replies; 8+ messages in thread
From: Dmitry Vyukov @ 2020-01-14 15:21 UTC (permalink / raw)
To: Mimi Zohar
Cc: syzbot, Lakshmi Ramasubramanian, Dmitry Kasatkin, James Morris,
linux-integrity, LKML, linux-security-module, Serge E. Hallyn,
syzkaller-bugs
On Tue, Jan 14, 2020 at 3:57 PM Mimi Zohar <zohar@linux.ibm.com> wrote:
>
> On Tue, 2020-01-14 at 14:58 +0100, Dmitry Vyukov wrote:
> > On Tue, Jan 14, 2020 at 2:56 PM syzbot
> > <syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com> wrote:
> > >
> > > Hello,
> > >
> > > syzbot found the following crash on:
> > >
> > > HEAD commit: 1b851f98 Add linux-next specific files for 20200114
> > > git tree: linux-next
> > > console output: https://syzkaller.appspot.com/x/log.txt?x=12bcbb25e00000
> > > kernel config: https://syzkaller.appspot.com/x/.config?x=3e7d9cf7ebfa08ad
> > > dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
> > > compiler: gcc (GCC) 9.0.0 20181231 (experimental)
> > >
> > > Unfortunately, I don't have any reproducer for this crash yet.
> > >
> > > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > > Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
> >
> > +Lakshmi, you seem to have submitted a number of changes to this file recently.
> >
> > This completely breaks linux-next testing for us, every kernel crashes
> > a few minutes after boot.
> >
> > 2020/01/14 14:45:00 vm-26: crash: inconsistent lock state in
> > ima_process_queued_keys
>
> Yikes! Are you running with an IMA policy?
I don't know.
> I assume this is being
> caused by commit 8f5d2d06f217 ("IMA: Defined timer to free queued
> keys". Does reverting it prevent this from happening?
The following seems to help, but don't know if it's the right fix or not.
diff --git a/security/integrity/ima/ima_asymmetric_keys.c
b/security/integrity/ima/ima_asymmetric_keys.c
index 61e478f9e8199..49d559501fe62 100644
--- a/security/integrity/ima/ima_asymmetric_keys.c
+++ b/security/integrity/ima/ima_asymmetric_keys.c
@@ -103,17 +103,18 @@ static bool ima_queue_key(struct key *keyring,
const void *payload,
{
bool queued = false;
struct ima_key_entry *entry;
+ unsigned long flags;
entry = ima_alloc_key_entry(keyring, payload, payload_len);
if (!entry)
return false;
- spin_lock(&ima_keys_lock);
+ spin_lock_irqsave(&ima_keys_lock, flags);
if (!ima_process_keys) {
list_add_tail(&entry->list, &ima_keys);
queued = true;
}
- spin_unlock(&ima_keys_lock);
+ spin_unlock_irqrestore(&ima_keys_lock, flags);
if (!queued)
ima_free_key_entry(entry);
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 15:21 ` Dmitry Vyukov
@ 2020-01-14 16:54 ` Lakshmi Ramasubramanian
2020-01-14 17:19 ` Lakshmi Ramasubramanian
1 sibling, 0 replies; 8+ messages in thread
From: Lakshmi Ramasubramanian @ 2020-01-14 16:54 UTC (permalink / raw)
To: Dmitry Vyukov, Mimi Zohar
Cc: syzbot, Dmitry Kasatkin, James Morris, linux-integrity, LKML,
linux-security-module, Serge E. Hallyn, syzkaller-bugs
I am investigating this.
thanks,
-lakshmi
On 1/14/2020 7:21 AM, Dmitry Vyukov wrote:
> On Tue, Jan 14, 2020 at 3:57 PM Mimi Zohar <zohar@linux.ibm.com> wrote:
>>
>> On Tue, 2020-01-14 at 14:58 +0100, Dmitry Vyukov wrote:
>>> On Tue, Jan 14, 2020 at 2:56 PM syzbot
>>> <syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com> wrote:
>>>>
>>>> Hello,
>>>>
>>>> syzbot found the following crash on:
>>>>
>>>> HEAD commit: 1b851f98 Add linux-next specific files for 20200114
>>>> git tree: linux-next
>>>> console output: https://syzkaller.appspot.com/x/log.txt?x=12bcbb25e00000
>>>> kernel config: https://syzkaller.appspot.com/x/.config?x=3e7d9cf7ebfa08ad
>>>> dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
>>>> compiler: gcc (GCC) 9.0.0 20181231 (experimental)
>>>>
>>>> Unfortunately, I don't have any reproducer for this crash yet.
>>>>
>>>> IMPORTANT: if you fix the bug, please add the following tag to the commit:
>>>> Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
>>>
>>> +Lakshmi, you seem to have submitted a number of changes to this file recently.
>>>
>>> This completely breaks linux-next testing for us, every kernel crashes
>>> a few minutes after boot.
>>>
>>> 2020/01/14 14:45:00 vm-26: crash: inconsistent lock state in
>>> ima_process_queued_keys
>>
>> Yikes! Are you running with an IMA policy?
>
> I don't know.
>
>> I assume this is being
>> caused by commit 8f5d2d06f217 ("IMA: Defined timer to free queued
>> keys". Does reverting it prevent this from happening?
>
> The following seems to help, but don't know if it's the right fix or not.
>
> diff --git a/security/integrity/ima/ima_asymmetric_keys.c
> b/security/integrity/ima/ima_asymmetric_keys.c
> index 61e478f9e8199..49d559501fe62 100644
> --- a/security/integrity/ima/ima_asymmetric_keys.c
> +++ b/security/integrity/ima/ima_asymmetric_keys.c
> @@ -103,17 +103,18 @@ static bool ima_queue_key(struct key *keyring,
> const void *payload,
> {
> bool queued = false;
> struct ima_key_entry *entry;
> + unsigned long flags;
>
> entry = ima_alloc_key_entry(keyring, payload, payload_len);
> if (!entry)
> return false;
>
> - spin_lock(&ima_keys_lock);
> + spin_lock_irqsave(&ima_keys_lock, flags);
> if (!ima_process_keys) {
> list_add_tail(&entry->list, &ima_keys);
> queued = true;
> }
> - spin_unlock(&ima_keys_lock);
> + spin_unlock_irqrestore(&ima_keys_lock, flags);
>
> if (!queued)
> ima_free_key_entry(entry);
>
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 15:21 ` Dmitry Vyukov
2020-01-14 16:54 ` Lakshmi Ramasubramanian
@ 2020-01-14 17:19 ` Lakshmi Ramasubramanian
1 sibling, 0 replies; 8+ messages in thread
From: Lakshmi Ramasubramanian @ 2020-01-14 17:19 UTC (permalink / raw)
To: Dmitry Vyukov, Mimi Zohar
Cc: syzbot, Dmitry Kasatkin, James Morris, linux-integrity, LKML,
linux-security-module, Serge E. Hallyn, syzkaller-bugs
Hi Dmitry,
> --- a/security/integrity/ima/ima_asymmetric_keys.c
> +++ b/security/integrity/ima/ima_asymmetric_keys.c
> @@ -103,17 +103,18 @@ static bool ima_queue_key(struct key *keyring,
> const void *payload,
> {
> bool queued = false;
> struct ima_key_entry *entry;
> + unsigned long flags;
>
> entry = ima_alloc_key_entry(keyring, payload, payload_len);
> if (!entry)
> return false;
>
> - spin_lock(&ima_keys_lock);
> + spin_lock_irqsave(&ima_keys_lock, flags);
> if (!ima_process_keys) {
> list_add_tail(&entry->list, &ima_keys);
> queued = true;
> }
> - spin_unlock(&ima_keys_lock);
> + spin_unlock_irqrestore(&ima_keys_lock, flags);
>
> if (!queued)
> ima_free_key_entry(entry);
>
Using sping_lock_irqsave() and spin_lock_irqrestore() in ima_queue_key()
is the right approach. Found a relevant blog below:
https://stackoverflow.com/questions/50637489/spin-lock-irqsave-in-interrupt-context
I think it would be safe to use the same spinlock functions in
ima_process_queued_keys() as well, but not a must.
Could you please confirm if your change fixed the crash?
I'll post a patch shortly.
thanks,
-lakshmi
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-14 13:56 inconsistent lock state in ima_process_queued_keys syzbot
2020-01-14 13:58 ` Dmitry Vyukov
@ 2020-01-18 3:14 ` syzbot
2020-01-18 5:22 ` Lakshmi Ramasubramanian
1 sibling, 1 reply; 8+ messages in thread
From: syzbot @ 2020-01-18 3:14 UTC (permalink / raw)
To: dmitry.kasatkin, dvyukov, jmorris, linux-integrity, linux-kernel,
linux-security-module, nramas, serge, syzkaller-bugs, zohar
syzbot has found a reproducer for the following crash on:
HEAD commit: 2747d5fd Add linux-next specific files for 20200116
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=14ee1cc9e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=22f506e7a3a37fe2
dashboard link: https://syzkaller.appspot.com/bug?extid=a4a503d7f37292ae1664
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=128b4495e00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=12b673b9e00000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
================================
WARNING: inconsistent lock state
5.5.0-rc6-next-20200116-syzkaller #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
kworker/u4:3/125 [HC0[0]:SC1[1]:HE1:SE0] takes:
ffffffff8a03ce58 (ima_keys_lock){+.?.}, at: spin_lock include/linux/spinlock.h:338 [inline]
ffffffff8a03ce58 (ima_keys_lock){+.?.}, at: ima_process_queued_keys+0x4f/0x320 security/integrity/ima/ima_asymmetric_keys.c:144
{SOFTIRQ-ON-W} state was registered at:
lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:338 [inline]
ima_queue_key security/integrity/ima/ima_asymmetric_keys.c:111 [inline]
ima_post_key_create_or_update+0x234/0x470 security/integrity/ima/ima_asymmetric_keys.c:194
key_create_or_update+0x6b8/0xcb0 security/keys/key.c:944
load_system_certificate_list+0x1ba/0x25e certs/system_keyring.c:161
do_one_initcall+0x120/0x820 init/main.c:1109
do_initcall_level init/main.c:1182 [inline]
do_initcalls init/main.c:1198 [inline]
do_basic_setup init/main.c:1218 [inline]
kernel_init_freeable+0x522/0x5d0 init/main.c:1402
kernel_init+0x12/0x1bf init/main.c:1309
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
irq event stamp: 15703140
hardirqs last enabled at (15703140): [<ffffffff87ee0813>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:168 [inline]
hardirqs last enabled at (15703140): [<ffffffff87ee0813>] _raw_spin_unlock_irq+0x23/0x80 kernel/locking/spinlock.c:199
hardirqs last disabled at (15703139): [<ffffffff87ee09fa>] __raw_spin_lock_irq include/linux/spinlock_api_smp.h:126 [inline]
hardirqs last disabled at (15703139): [<ffffffff87ee09fa>] _raw_spin_lock_irq+0x3a/0x80 kernel/locking/spinlock.c:167
softirqs last enabled at (15702640): [<ffffffff87cf9855>] spin_unlock_bh include/linux/spinlock.h:383 [inline]
softirqs last enabled at (15702640): [<ffffffff87cf9855>] batadv_nc_purge_paths+0x265/0x370 net/batman-adv/network-coding.c:470
softirqs last disabled at (15702651): [<ffffffff8147a05b>] invoke_softirq kernel/softirq.c:373 [inline]
softirqs last disabled at (15702651): [<ffffffff8147a05b>] irq_exit+0x19b/0x1e0 kernel/softirq.c:413
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(ima_keys_lock);
<Interrupt>
lock(ima_keys_lock);
*** DEADLOCK ***
4 locks held by kworker/u4:3/125:
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: __write_once_size include/linux/compiler.h:250 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:869 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: set_work_data kernel/workqueue.c:615 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:642 [inline]
#0: ffff88821512a928 ((wq_completion)bat_events){+.+.}, at: process_one_work+0x8dd/0x17a0 kernel/workqueue.c:2235
#1: ffffc90001397dc0 ((work_completion)(&(&bat_priv->nc.work)->work)){+.+.}, at: process_one_work+0x917/0x17a0 kernel/workqueue.c:2239
#2: ffffffff89bb0400 (rcu_read_lock){....}, at: batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:405 [inline]
#2: ffffffff89bb0400 (rcu_read_lock){....}, at: batadv_nc_worker+0xe3/0x760 net/batman-adv/network-coding.c:718
#3: ffffc90000d98d50 ((&ima_key_queue_timer)){+.-.}, at: lockdep_copy_map include/linux/lockdep.h:172 [inline]
#3: ffffc90000d98d50 ((&ima_key_queue_timer)){+.-.}, at: call_timer_fn+0xe0/0x780 kernel/time/timer.c:1394
stack backtrace:
CPU: 1 PID: 125 Comm: kworker/u4:3 Not tainted 5.5.0-rc6-next-20200116-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: bat_events batadv_nc_worker
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x197/0x210 lib/dump_stack.c:118
print_usage_bug.cold+0x327/0x378 kernel/locking/lockdep.c:3100
valid_state kernel/locking/lockdep.c:3111 [inline]
mark_lock_irq kernel/locking/lockdep.c:3308 [inline]
mark_lock+0xbb4/0x1220 kernel/locking/lockdep.c:3665
mark_usage kernel/locking/lockdep.c:3565 [inline]
__lock_acquire+0x1e8e/0x4a00 kernel/locking/lockdep.c:3908
lock_acquire+0x190/0x410 kernel/locking/lockdep.c:4484
__raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
_raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:151
spin_lock include/linux/spinlock.h:338 [inline]
ima_process_queued_keys+0x4f/0x320 security/integrity/ima/ima_asymmetric_keys.c:144
ima_timer_handler+0x15/0x20 security/integrity/ima/ima_asymmetric_keys.c:46
call_timer_fn+0x1ac/0x780 kernel/time/timer.c:1404
expire_timers kernel/time/timer.c:1449 [inline]
__run_timers kernel/time/timer.c:1773 [inline]
__run_timers kernel/time/timer.c:1740 [inline]
run_timer_softirq+0x6c3/0x1790 kernel/time/timer.c:1786
__do_softirq+0x262/0x98c kernel/softirq.c:292
invoke_softirq kernel/softirq.c:373 [inline]
irq_exit+0x19b/0x1e0 kernel/softirq.c:413
exiting_irq arch/x86/include/asm/apic.h:536 [inline]
smp_apic_timer_interrupt+0x1a3/0x610 arch/x86/kernel/apic/apic.c:1137
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:829
</IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:752 [inline]
RIP: 0010:lock_acquire+0x20b/0x410 kernel/locking/lockdep.c:4487
Code: 9c 08 00 00 00 00 00 00 48 c1 e8 03 80 3c 10 00 0f 85 d3 01 00 00 48 83 3d 49 7d 58 08 00 0f 84 53 01 00 00 48 8b 7d c8 57 9d <0f> 1f 44 00 00 48 8d 65 d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 65 8b
RSP: 0018:ffffc90001397c70 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff136774f RBX: ffff8880a922c600 RCX: ffffffff815ae240
RDX: dffffc0000000000 RSI: 0000000000000008 RDI: 0000000000000286
RBP: ffffc90001397cb8 R08: 1ffffffff16a51a4 R09: fffffbfff16a51a5
R10: ffff8880a922cef0 R11: ffff8880a922c600 R12: ffffffff89bb0400
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000002
rcu_lock_acquire include/linux/rcupdate.h:208 [inline]
rcu_read_lock include/linux/rcupdate.h:601 [inline]
batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:407 [inline]
batadv_nc_worker+0x117/0x760 net/batman-adv/network-coding.c:718
process_one_work+0xa05/0x17a0 kernel/workqueue.c:2264
worker_thread+0x98/0xe40 kernel/workqueue.c:2410
kthread+0x361/0x430 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: inconsistent lock state in ima_process_queued_keys
2020-01-18 3:14 ` syzbot
@ 2020-01-18 5:22 ` Lakshmi Ramasubramanian
0 siblings, 0 replies; 8+ messages in thread
From: Lakshmi Ramasubramanian @ 2020-01-18 5:22 UTC (permalink / raw)
To: syzbot, dmitry.kasatkin, dvyukov, jmorris, linux-integrity,
linux-kernel, linux-security-module, serge, syzkaller-bugs,
zohar
On 1/17/2020 7:14 PM, syzbot wrote:
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+a4a503d7f37292ae1664@syzkaller.appspotmail.com
>
> ================================
> WARNING: inconsistent lock state
> 5.5.0-rc6-next-20200116-syzkaller #0 Not tainted
> --------------------------------
> inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
> kworker/u4:3/125 [HC0[0]:SC1[1]:HE1:SE0] takes:
> ffffffff8a03ce58 (ima_keys_lock){+.?.}, at: spin_lock include/linux/spinlock.h:338 [inline]
> ffffffff8a03ce58 (ima_keys_lock){+.?.}, at: ima_process_queued_keys+0x4f/0x320 security/integrity/ima/ima_asymmetric_keys.c:144
> {SOFTIRQ-ON-W} state was registered at:
The fix for this issue is in next-integrity branch. Should be merged to
linux-next shortly.
-lakshmi
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2020-01-18 5:22 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-01-14 13:56 inconsistent lock state in ima_process_queued_keys syzbot
2020-01-14 13:58 ` Dmitry Vyukov
2020-01-14 14:56 ` Mimi Zohar
2020-01-14 15:21 ` Dmitry Vyukov
2020-01-14 16:54 ` Lakshmi Ramasubramanian
2020-01-14 17:19 ` Lakshmi Ramasubramanian
2020-01-18 3:14 ` syzbot
2020-01-18 5:22 ` Lakshmi Ramasubramanian
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).