[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 55.188173][ T26] audit: type=1800 audit(1567404555.281:25): pid=8581 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 55.212945][ T26] audit: type=1800 audit(1567404555.281:26): pid=8581 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 55.257223][ T26] audit: type=1800 audit(1567404555.281:27): pid=8581 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="restorecond" dev="sda1" ino=2436 res=0 [....] Starting periodic command scheduler: cron[?25l[?1c7[ ok 8[?25h[?0c. [....] Starting OpenBSD Secure Shell server: sshd[?25l[?1c7[ ok 8[?25h[?0c. Debian GNU/Linux 7 syzkaller ttyS0 Warning: Permanently added '10.128.0.216' (ECDSA) to the list of known hosts. executing program syzkaller login: [ 65.639524][ C0] [ 65.641879][ C0] ======================================================== [ 65.649041][ C0] WARNING: possible irq lock inversion dependency detected [ 65.656294][ C0] 5.3.0-rc6-next-20190830 #75 Not tainted [ 65.661980][ C0] -------------------------------------------------------- [ 65.669166][ C0] ksoftirqd/0/9 just changed the state of lock: [ 65.675396][ C0] ffff888096315b58 (&(&ctx->ctx_lock)->rlock){..-.}, at: free_ioctx_users+0x2d/0x490 [ 65.684837][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 65.692343][ C0] (&fiq->waitq){+.+.} [ 65.692348][ C0] [ 65.692348][ C0] [ 65.692348][ C0] and interrupts could create inverse lock ordering between them. [ 65.692348][ C0] [ 65.710743][ C0] [ 65.710743][ C0] other info that might help us debug this: [ 65.718772][ C0] Possible interrupt unsafe locking scenario: [ 65.718772][ C0] [ 65.727059][ C0] CPU0 CPU1 [ 65.732396][ C0] ---- ---- [ 65.737731][ C0] lock(&fiq->waitq); [ 65.741784][ C0] local_irq_disable(); [ 65.748513][ C0] lock(&(&ctx->ctx_lock)->rlock); [ 65.756196][ C0] lock(&fiq->waitq); [ 65.762753][ C0] [ 65.766179][ C0] lock(&(&ctx->ctx_lock)->rlock); [ 65.771523][ C0] [ 65.771523][ C0] *** DEADLOCK *** [ 65.771523][ C0] [ 65.779640][ C0] 2 locks held by ksoftirqd/0/9: [ 65.784544][ C0] #0: ffffffff88fa7e40 (rcu_callback){....}, at: rcu_core+0x60e/0x1560 [ 65.792856][ C0] #1: ffffffff88fa7e80 (rcu_read_lock_sched){....}, at: percpu_ref_switch_to_atomic_rcu+0x20e/0x570 [ 65.803701][ C0] [ 65.803701][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 65.813044][ C0] -> (&fiq->waitq){+.+.} { [ 65.817520][ C0] HARDIRQ-ON-W at: [ 65.821567][ C0] lock_acquire+0x190/0x410 [ 65.827868][ C0] _raw_spin_lock+0x2f/0x40 [ 65.834167][ C0] flush_bg_queue+0x1f1/0x3b0 [ 65.840639][ C0] fuse_request_queue_background+0x2f8/0x5b0 [ 65.848414][ C0] fuse_request_send_background+0x58/0x110 [ 65.856099][ C0] cuse_channel_open+0x5c3/0x839 [ 65.862839][ C0] misc_open+0x395/0x4c0 [ 65.868900][ C0] chrdev_open+0x245/0x6b0 [ 65.875136][ C0] do_dentry_open+0x4df/0x1250 [ 65.881712][ C0] vfs_open+0xa0/0xd0 [ 65.887509][ C0] path_openat+0x10e9/0x46d0 [ 65.893899][ C0] do_filp_open+0x1a1/0x280 [ 65.900203][ C0] do_sys_open+0x3fe/0x5d0 [ 65.906431][ C0] __x64_sys_openat+0x9d/0x100 [ 65.913024][ C0] do_syscall_64+0xfa/0x760 [ 65.919324][ C0] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.927020][ C0] SOFTIRQ-ON-W at: [ 65.931068][ C0] lock_acquire+0x190/0x410 [ 65.937367][ C0] _raw_spin_lock+0x2f/0x40 [ 65.943751][ C0] flush_bg_queue+0x1f1/0x3b0 [ 65.950220][ C0] fuse_request_queue_background+0x2f8/0x5b0 [ 65.957996][ C0] fuse_request_send_background+0x58/0x110 [ 65.965854][ C0] cuse_channel_open+0x5c3/0x839 [ 65.972588][ C0] misc_open+0x395/0x4c0 [ 65.978624][ C0] chrdev_open+0x245/0x6b0 [ 65.984933][ C0] do_dentry_open+0x4df/0x1250 [ 65.991496][ C0] vfs_open+0xa0/0xd0 [ 65.997290][ C0] path_openat+0x10e9/0x46d0 [ 66.003705][ C0] do_filp_open+0x1a1/0x280 [ 66.010006][ C0] do_sys_open+0x3fe/0x5d0 [ 66.016217][ C0] __x64_sys_openat+0x9d/0x100 [ 66.022776][ C0] do_syscall_64+0xfa/0x760 [ 66.029077][ C0] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 66.036757][ C0] INITIAL USE at: [ 66.040716][ C0] lock_acquire+0x190/0x410 [ 66.046927][ C0] _raw_spin_lock+0x2f/0x40 [ 66.053154][ C0] flush_bg_queue+0x1f1/0x3b0 [ 66.059539][ C0] fuse_request_queue_background+0x2f8/0x5b0 [ 66.067227][ C0] fuse_request_send_background+0x58/0x110 [ 66.074760][ C0] cuse_channel_open+0x5c3/0x839 [ 66.081414][ C0] misc_open+0x395/0x4c0 [ 66.087366][ C0] chrdev_open+0x245/0x6b0 [ 66.093493][ C0] do_dentry_open+0x4df/0x1250 [ 66.099996][ C0] vfs_open+0xa0/0xd0 [ 66.105695][ C0] path_openat+0x10e9/0x46d0 [ 66.112012][ C0] do_filp_open+0x1a1/0x280 [ 66.118226][ C0] do_sys_open+0x3fe/0x5d0 [ 66.124372][ C0] __x64_sys_openat+0x9d/0x100 [ 66.130850][ C0] do_syscall_64+0xfa/0x760 [ 66.137165][ C0] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 66.144764][ C0] } [ 66.147336][ C0] ... key at: [] __key.44810+0x0/0x40 [ 66.154863][ C0] ... acquired at: [ 66.158746][ C0] _raw_spin_lock+0x2f/0x40 [ 66.163428][ C0] io_submit_one+0xefa/0x2ef0 [ 66.168258][ C0] __x64_sys_io_submit+0x1bd/0x570 [ 66.173551][ C0] do_syscall_64+0xfa/0x760 [ 66.178210][ C0] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 66.184248][ C0] [ 66.186548][ C0] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 66.192067][ C0] IN-SOFTIRQ-W at: [ 66.196029][ C0] lock_acquire+0x190/0x410 [ 66.202156][ C0] _raw_spin_lock_irq+0x60/0x80 [ 66.208630][ C0] free_ioctx_users+0x2d/0x490 [ 66.215023][ C0] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 66.222799][ C0] rcu_core+0x581/0x1560 [ 66.228662][ C0] rcu_core_si+0x9/0x10 [ 66.234440][ C0] __do_softirq+0x262/0x98c [ 66.240581][ C0] run_ksoftirqd+0x8e/0x110 [ 66.246708][ C0] smpboot_thread_fn+0x6a3/0xa40 [ 66.253288][ C0] kthread+0x361/0x430 [ 66.258987][ C0] ret_from_fork+0x24/0x30 [ 66.265019][ C0] INITIAL USE at: [ 66.268889][ C0] lock_acquire+0x190/0x410 [ 66.274925][ C0] _raw_spin_lock_irq+0x60/0x80 [ 66.281316][ C0] io_submit_one+0xeb5/0x2ef0 [ 66.288786][ C0] __x64_sys_io_submit+0x1bd/0x570 [ 66.295443][ C0] do_syscall_64+0xfa/0x760 [ 66.301487][ C0] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 66.308933][ C0] } [ 66.311430][ C0] ... key at: [] __key.54358+0x0/0x40 [ 66.318853][ C0] ... acquired at: [ 66.322635][ C0] mark_lock+0x517/0x1220 [ 66.327106][ C0] __lock_acquire+0x1e8e/0x4a00 [ 66.332104][ C0] lock_acquire+0x190/0x410 [ 66.336760][ C0] _raw_spin_lock_irq+0x60/0x80 [ 66.341758][ C0] free_ioctx_users+0x2d/0x490 [ 66.346673][ C0] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 66.352978][ C0] rcu_core+0x581/0x1560 [ 66.357365][ C0] rcu_core_si+0x9/0x10 [ 66.361667][ C0] __do_softirq+0x262/0x98c [ 66.366316][ C0] run_ksoftirqd+0x8e/0x110 [ 66.371000][ C0] smpboot_thread_fn+0x6a3/0xa40 [ 66.376088][ C0] kthread+0x361/0x430 [ 66.380301][ C0] ret_from_fork+0x24/0x30 [ 66.384857][ C0] [ 66.387178][ C0] [ 66.387178][ C0] stack backtrace: [ 66.393047][ C0] CPU: 0 PID: 9 Comm: ksoftirqd/0 Not tainted 5.3.0-rc6-next-20190830 #75 [ 66.401527][ C0] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 66.411553][ C0] Call Trace: [ 66.414843][ C0] dump_stack+0x172/0x1f0 [ 66.419174][ C0] print_irq_inversion_bug.part.0+0x2e4/0x2f1 [ 66.425216][ C0] check_usage_forwards.cold+0x20/0x29 [ 66.430651][ C0] ? check_usage_backwards+0x330/0x330 [ 66.436087][ C0] ? save_trace+0x3e/0x8c0 [ 66.440481][ C0] mark_lock+0x517/0x1220 [ 66.444782][ C0] ? check_usage_backwards+0x330/0x330 [ 66.450215][ C0] __lock_acquire+0x1e8e/0x4a00 [ 66.455060][ C0] ? __kasan_check_read+0x11/0x20 [ 66.460066][ C0] ? mark_lock+0xc2/0x1220 [ 66.464458][ C0] ? mark_held_locks+0xf0/0xf0 [ 66.469196][ C0] lock_acquire+0x190/0x410 [ 66.473674][ C0] ? free_ioctx_users+0x2d/0x490 [ 66.478586][ C0] _raw_spin_lock_irq+0x60/0x80 [ 66.483409][ C0] ? free_ioctx_users+0x2d/0x490 [ 66.489191][ C0] free_ioctx_users+0x2d/0x490 [ 66.493931][ C0] ? rcu_dynticks_curr_cpu_in_eqs+0x54/0xb0 [ 66.499817][ C0] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 66.505955][ C0] ? percpu_ref_exit+0xd0/0xd0 [ 66.510711][ C0] rcu_core+0x581/0x1560 [ 66.514931][ C0] ? __rcu_read_unlock+0x6b0/0x6b0 [ 66.520024][ C0] ? rcu_read_lock_sched_held+0x9c/0xd0 [ 66.525542][ C0] ? rcu_read_lock_any_held.part.0+0x50/0x50 [ 66.531495][ C0] rcu_core_si+0x9/0x10 [ 66.535628][ C0] __do_softirq+0x262/0x98c [ 66.540107][ C0] ? takeover_tasklets+0x820/0x820 [ 66.545198][ C0] run_ksoftirqd+0x8e/0x110 [ 66.549675][ C0] smpboot_thread_fn+0x6a3/0xa40 [ 66.554594][ C0] ? smpboot_register_percpu_thread+0x390/0x390 [ 66.560916][ C0] ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20 [ 66.567168][ C0] ? __kthread_parkme+0x108/0x1c0 [ 66.572169][ C0] ? __kasan_check_read+0x11/0x20 [ 66.577168][ C0] kthread+0x361/0x430 [ 66.581212][ C0] ? smpboot_register_percpu_thread+0x390/0x390 [ 66.587425][ C0] ? kthread_cancel_delayed_work_sync+0x20/0x20 [