[ 35.586859][ T27] audit: type=1800 audit(1554517851.690:28): pid=7523 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="ssh" dev="sda1" ino=2417 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. [ 36.410267][ T27] audit: type=1800 audit(1554517852.560:29): pid=7523 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="rc.local" dev="sda1" ino=2432 res=0 [ 36.430874][ T27] audit: type=1800 audit(1554517852.570:30): pid=7523 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="rmnologin" dev="sda1" ino=2423 res=0 [....] startpar: service(s) returned failure: ssh ...[?25l[?1c7[FAIL8[?25h[?0c failed! Debian GNU/Linux 7 syzkaller ttyS0 Warning: Permanently added '10.128.0.204' (ECDSA) to the list of known hosts. executing program syzkaller login: [ 65.145210][ T7699] [ 65.147709][ T7699] ======================================================== [ 65.155122][ T7699] WARNING: possible irq lock inversion dependency detected [ 65.162845][ T7699] 5.1.0-rc3+ #53 Not tainted [ 65.167434][ T7699] -------------------------------------------------------- [ 65.174989][ T7699] syz-executor153/7699 just changed the state of lock: [ 65.181826][ T7699] 000000009163c420 (&ctx->fault_pending_wqh){+.+.}, at: userfaultfd_release+0x48e/0x6d0 [ 65.192359][ T7699] but this lock was taken by another, SOFTIRQ-safe lock in the past: [ 65.200509][ T7699] (&(&ctx->ctx_lock)->rlock){..-.} [ 65.200517][ T7699] [ 65.200517][ T7699] [ 65.200517][ T7699] and interrupts could create inverse lock ordering between them. [ 65.200517][ T7699] [ 65.220506][ T7699] [ 65.220506][ T7699] other info that might help us debug this: [ 65.228549][ T7699] Chain exists of: [ 65.228549][ T7699] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 65.228549][ T7699] [ 65.242770][ T7699] Possible interrupt unsafe locking scenario: [ 65.242770][ T7699] [ 65.251288][ T7699] CPU0 CPU1 [ 65.256635][ T7699] ---- ---- [ 65.261998][ T7699] lock(&ctx->fault_pending_wqh); [ 65.267170][ T7699] local_irq_disable(); [ 65.274341][ T7699] lock(&(&ctx->ctx_lock)->rlock); [ 65.282155][ T7699] lock(&ctx->fd_wqh); [ 65.288821][ T7699] [ 65.292255][ T7699] lock(&(&ctx->ctx_lock)->rlock); [ 65.297599][ T7699] [ 65.297599][ T7699] *** DEADLOCK *** [ 65.297599][ T7699] [ 65.305721][ T7699] no locks held by syz-executor153/7699. [ 65.311336][ T7699] [ 65.311336][ T7699] the shortest dependencies between 2nd lock and 1st lock: [ 65.320887][ T7699] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 65.326825][ T7699] IN-SOFTIRQ-W at: [ 65.330975][ T7699] lock_acquire+0x16f/0x3f0 [ 65.337626][ T7699] _raw_spin_lock_irq+0x60/0x80 [ 65.344474][ T7699] free_ioctx_users+0x2d/0x4a0 [ 65.351834][ T7699] percpu_ref_switch_to_atomic_rcu+0x3e7/0x520 [ 65.359973][ T7699] rcu_core+0x928/0x1390 [ 65.366194][ T7699] __do_softirq+0x266/0x95a [ 65.372676][ T7699] irq_exit+0x180/0x1d0 [ 65.379096][ T7699] smp_apic_timer_interrupt+0x14a/0x570 [ 65.386742][ T7699] apic_timer_interrupt+0xf/0x20 [ 65.393683][ T7699] native_safe_halt+0x2/0x10 [ 65.400257][ T7699] arch_cpu_idle+0x10/0x20 [ 65.406788][ T7699] default_idle_call+0x36/0x90 [ 65.413952][ T7699] do_idle+0x386/0x570 [ 65.420366][ T7699] cpu_startup_entry+0x1b/0x20 [ 65.427241][ T7699] start_secondary+0x360/0x4d0 [ 65.434312][ T7699] secondary_startup_64+0xa4/0xb0 [ 65.441316][ T7699] INITIAL USE at: [ 65.445658][ T7699] lock_acquire+0x16f/0x3f0 [ 65.452135][ T7699] _raw_spin_lock_irq+0x60/0x80 [ 65.458880][ T7699] io_submit_one+0xaec/0x2f90 [ 65.465566][ T7699] __x64_sys_io_submit+0x1bd/0x580 [ 65.472577][ T7699] do_syscall_64+0x103/0x610 [ 65.480219][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.488108][ T7699] } [ 65.490779][ T7699] ... key at: [] __key.52649+0x0/0x40 [ 65.498510][ T7699] ... acquired at: [ 65.503590][ T7699] lock_acquire+0x16f/0x3f0 [ 65.508388][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.513304][ T7699] io_submit_one+0xb31/0x2f90 [ 65.518301][ T7699] __x64_sys_io_submit+0x1bd/0x580 [ 65.524582][ T7699] do_syscall_64+0x103/0x610 [ 65.529871][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.536115][ T7699] [ 65.538432][ T7699] -> (&ctx->fd_wqh){....} { [ 65.543418][ T7699] INITIAL USE at: [ 65.547532][ T7699] lock_acquire+0x16f/0x3f0 [ 65.553829][ T7699] _raw_spin_lock_irqsave+0x95/0xcd [ 65.561207][ T7699] add_wait_queue+0x4c/0x170 [ 65.567525][ T7699] aio_poll_queue_proc+0x9e/0x110 [ 65.574283][ T7699] userfaultfd_poll+0x93/0x220 [ 65.580771][ T7699] io_submit_one+0xa8a/0x2f90 [ 65.587174][ T7699] __x64_sys_io_submit+0x1bd/0x580 [ 65.594124][ T7699] do_syscall_64+0x103/0x610 [ 65.600442][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.608049][ T7699] } [ 65.610635][ T7699] ... key at: [] __key.45459+0x0/0x40 [ 65.618148][ T7699] ... acquired at: [ 65.622027][ T7699] lock_acquire+0x16f/0x3f0 [ 65.626674][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.631561][ T7699] userfaultfd_read+0x540/0x1940 [ 65.636672][ T7699] __vfs_read+0x8d/0x110 [ 65.641081][ T7699] vfs_read+0x194/0x3e0 [ 65.645542][ T7699] ksys_read+0xea/0x1f0 [ 65.649859][ T7699] __x64_sys_read+0x73/0xb0 [ 65.654952][ T7699] do_syscall_64+0x103/0x610 [ 65.659716][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.665753][ T7699] [ 65.668195][ T7699] -> (&ctx->fault_pending_wqh){+.+.} { [ 65.673866][ T7699] HARDIRQ-ON-W at: [ 65.677835][ T7699] lock_acquire+0x16f/0x3f0 [ 65.684163][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.690431][ T7699] userfaultfd_release+0x48e/0x6d0 [ 65.697672][ T7699] __fput+0x2e5/0x8d0 [ 65.703400][ T7699] ____fput+0x16/0x20 [ 65.709028][ T7699] task_work_run+0x14a/0x1c0 [ 65.715263][ T7699] do_exit+0x90a/0x2fa0 [ 65.721048][ T7699] do_group_exit+0x135/0x370 [ 65.727388][ T7699] get_signal+0x399/0x1d50 [ 65.733542][ T7699] do_signal+0x87/0x1940 [ 65.739523][ T7699] exit_to_usermode_loop+0x244/0x2c0 [ 65.746590][ T7699] do_syscall_64+0x52d/0x610 [ 65.752815][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.760335][ T7699] SOFTIRQ-ON-W at: [ 65.764299][ T7699] lock_acquire+0x16f/0x3f0 [ 65.770568][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.776710][ T7699] userfaultfd_release+0x48e/0x6d0 [ 65.783617][ T7699] __fput+0x2e5/0x8d0 [ 65.789224][ T7699] ____fput+0x16/0x20 [ 65.795043][ T7699] task_work_run+0x14a/0x1c0 [ 65.801334][ T7699] do_exit+0x90a/0x2fa0 [ 65.807328][ T7699] do_group_exit+0x135/0x370 [ 65.813838][ T7699] get_signal+0x399/0x1d50 [ 65.819889][ T7699] do_signal+0x87/0x1940 [ 65.825771][ T7699] exit_to_usermode_loop+0x244/0x2c0 [ 65.832792][ T7699] do_syscall_64+0x52d/0x610 [ 65.839042][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.846560][ T7699] INITIAL USE at: [ 65.851341][ T7699] lock_acquire+0x16f/0x3f0 [ 65.857466][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.863526][ T7699] userfaultfd_read+0x540/0x1940 [ 65.870098][ T7699] __vfs_read+0x8d/0x110 [ 65.876070][ T7699] vfs_read+0x194/0x3e0 [ 65.881764][ T7699] ksys_read+0xea/0x1f0 [ 65.887629][ T7699] __x64_sys_read+0x73/0xb0 [ 65.893821][ T7699] do_syscall_64+0x103/0x610 [ 65.899956][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.907505][ T7699] } [ 65.910008][ T7699] ... key at: [] __key.45456+0x0/0x40 [ 65.917489][ T7699] ... acquired at: [ 65.921381][ T7699] mark_lock+0x427/0x1380 [ 65.925876][ T7699] __lock_acquire+0x1317/0x3fb0 [ 65.930894][ T7699] lock_acquire+0x16f/0x3f0 [ 65.935688][ T7699] _raw_spin_lock+0x2f/0x40 [ 65.940496][ T7699] userfaultfd_release+0x48e/0x6d0 [ 65.945768][ T7699] __fput+0x2e5/0x8d0 [ 65.949903][ T7699] ____fput+0x16/0x20 [ 65.954314][ T7699] task_work_run+0x14a/0x1c0 [ 65.959063][ T7699] do_exit+0x90a/0x2fa0 [ 65.963427][ T7699] do_group_exit+0x135/0x370 [ 65.968176][ T7699] get_signal+0x399/0x1d50 [ 65.972753][ T7699] do_signal+0x87/0x1940 [ 65.977143][ T7699] exit_to_usermode_loop+0x244/0x2c0 [ 65.982758][ T7699] do_syscall_64+0x52d/0x610 [ 65.987517][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 65.993563][ T7699] [ 65.995876][ T7699] [ 65.995876][ T7699] stack backtrace: [ 66.006367][ T7699] CPU: 1 PID: 7699 Comm: syz-executor153 Not tainted 5.1.0-rc3+ #53 [ 66.014416][ T7699] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 66.024458][ T7699] Call Trace: [ 66.027750][ T7699] dump_stack+0x172/0x1f0 [ 66.032067][ T7699] print_irq_inversion_bug.part.0+0x2c0/0x2cd [ 66.038231][ T7699] check_usage_backwards.cold+0x1d/0x26 [ 66.043783][ T7699] ? print_shortest_lock_dependencies+0x90/0x90 [ 66.050025][ T7699] ? save_stack_trace+0x1a/0x20 [ 66.054865][ T7699] ? depot_save_stack+0x1de/0x460 [ 66.059875][ T7699] mark_lock+0x427/0x1380 [ 66.064315][ T7699] ? print_shortest_lock_dependencies+0x90/0x90 [ 66.070549][ T7699] __lock_acquire+0x1317/0x3fb0 [ 66.075499][ T7699] ? trace_hardirqs_off+0x62/0x220 [ 66.080591][ T7699] ? kasan_check_read+0x11/0x20 [ 66.085541][ T7699] ? mark_held_locks+0xf0/0xf0 [ 66.090303][ T7699] ? save_stack+0xa9/0xd0 [ 66.095571][ T7699] ? save_stack+0x45/0xd0 [ 66.100001][ T7699] ? __kasan_slab_free+0x102/0x150 [ 66.105105][ T7699] ? kasan_slab_free+0xe/0x10 [ 66.109766][ T7699] ? kmem_cache_free+0x86/0x260 [ 66.114606][ T7699] ? free_fs_struct+0x4f/0x70 [ 66.119428][ T7699] ? exit_fs+0xf0/0x130 [ 66.123840][ T7699] lock_acquire+0x16f/0x3f0 [ 66.128413][ T7699] ? userfaultfd_release+0x48e/0x6d0 [ 66.133697][ T7699] _raw_spin_lock+0x2f/0x40 [ 66.138259][ T7699] ? userfaultfd_release+0x48e/0x6d0 [ 66.143537][ T7699] userfaultfd_release+0x48e/0x6d0 [ 66.148630][ T7699] ? userfaultfd_wake_function+0x2f0/0x2f0 [ 66.154537][ T7699] ? __sanitizer_cov_trace_const_cmp2+0x18/0x20 [ 66.160863][ T7699] ? ima_file_free+0xc9/0x4a0 [ 66.165715][ T7699] ? __might_sleep+0x95/0x190 [ 66.170392][ T7699] ? userfaultfd_wake_function+0x2f0/0x2f0 [ 66.176188][ T7699] __fput+0x2e5/0x8d0 [ 66.180169][ T7699] ____fput+0x16/0x20 [ 66.184148][ T7699] task_work_run+0x14a/0x1c0 [ 66.188727][ T7699] do_exit+0x90a/0x2fa0 [ 66.192864][ T7699] ? get_signal+0x331/0x1d50 [ 66.197508][ T7699] ? mm_update_next_owner+0x640/0x640 [ 66.202876][ T7699] ? kasan_check_write+0x14/0x20 [ 66.207809][ T7699] ? _raw_spin_unlock_irq+0x28/0x90 [ 66.212997][ T7699] ? get_signal+0x331/0x1d50 [ 66.217700][ T7699] ? _raw_spin_unlock_irq+0x28/0x90 [ 66.222901][ T7699] do_group_exit+0x135/0x370 [ 66.227691][ T7699] get_signal+0x399/0x1d50 [ 66.232296][ T7699] ? fsnotify+0xbc0/0xbc0 [ 66.236933][ T7699] ? fsnotify_first_mark+0x210/0x210 [ 66.242227][ T7699] do_signal+0x87/0x1940 [ 66.246461][ T7699] ? __vfs_read+0x95/0x110 [ 66.250866][ T7699] ? userfaultfd_event_wait_completion+0xa50/0xa50 [ 66.257375][ T7699] ? setup_sigcontext+0x7d0/0x7d0 [ 66.262494][ T7699] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 66.268732][ T7699] ? vfs_read+0x15d/0x3e0 [ 66.273834][ T7699] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20 [ 66.280054][ T7699] ? ksys_read+0x166/0x1f0 [ 66.284555][ T7699] ? exit_to_usermode_loop+0x43/0x2c0 [ 66.289918][ T7699] ? do_syscall_64+0x52d/0x610 [ 66.294663][ T7699] ? exit_to_usermode_loop+0x43/0x2c0 [ 66.300023][ T7699] ? lockdep_hardirqs_on+0x418/0x5d0 [ 66.305305][ T7699] ? trace_hardirqs_on+0x67/0x230 [ 66.310413][ T7699] exit_to_usermode_loop+0x244/0x2c0 [ 66.315810][ T7699] do_syscall_64+0x52d/0x610 [ 66.320521][ T7699] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 66.326597][ T7699] RIP: 0033:0x441279 [ 66.330681][ T7699] Code: Bad RIP value. [ 66.334727][ T7699] RSP: 002b:00007ffe387e6ff8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 executing program [ 66.343320][ T7699] RAX: fffffffffffffe00 RBX: 0000000000000003 RCX: 0000000000441279 [ 66.351842][ T7699] RDX: 0000000000000107 RSI: 0000000020000180 RDI: 0000000000000004 [ 66.359965][ T7699] RBP: 00000000006cb018 R08: 00000000004002c8 R09: 00000000004002c8 [ 66.367934][ T7699] R10: 00000000004002c8 R11: 0000000000000246 R12: 00000000004020a0 [ 66.376489][ T7699] R13: 0000000000402130 R14: 0000000000000000 R15: 0000000000000000 executing program