[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 43.932070][ T26] audit: type=1800 audit(1561819901.713:25): pid=7933 uid=0 auid=4294967295 ses=4294967295 subj=_ op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 43.960045][ T26] audit: type=1800 audit(1561819901.713:26): pid=7933 uid=0 auid=4294967295 ses=4294967295 subj=_ op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 43.995641][ T26] audit: type=1800 audit(1561819901.713:27): pid=7933 uid=0 auid=4294967295 ses=4294967295 subj=_ 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.222' (ECDSA) to the list of known hosts. 2019/06/29 14:51:54 parsed 1 programs 2019/06/29 14:51:56 executed programs: 0 syzkaller login: [ 58.715562][ T8102] IPVS: ftp: loaded support on port[0] = 21 [ 58.769372][ T8102] chnl_net:caif_netlink_parms(): no params data found [ 58.793682][ T8102] bridge0: port 1(bridge_slave_0) entered blocking state [ 58.801604][ T8102] bridge0: port 1(bridge_slave_0) entered disabled state [ 58.809472][ T8102] device bridge_slave_0 entered promiscuous mode [ 58.817170][ T8102] bridge0: port 2(bridge_slave_1) entered blocking state [ 58.824352][ T8102] bridge0: port 2(bridge_slave_1) entered disabled state [ 58.831938][ T8102] device bridge_slave_1 entered promiscuous mode [ 58.846815][ T8102] bond0: Enslaving bond_slave_0 as an active interface with an up link [ 58.856953][ T8102] bond0: Enslaving bond_slave_1 as an active interface with an up link [ 58.873411][ T8102] team0: Port device team_slave_0 added [ 58.880663][ T8102] team0: Port device team_slave_1 added [ 58.941307][ T8102] device hsr_slave_0 entered promiscuous mode [ 58.999368][ T8102] device hsr_slave_1 entered promiscuous mode [ 59.050370][ T8102] bridge0: port 2(bridge_slave_1) entered blocking state [ 59.057686][ T8102] bridge0: port 2(bridge_slave_1) entered forwarding state [ 59.065437][ T8102] bridge0: port 1(bridge_slave_0) entered blocking state [ 59.072539][ T8102] bridge0: port 1(bridge_slave_0) entered forwarding state [ 59.101821][ T8102] 8021q: adding VLAN 0 to HW filter on device bond0 [ 59.115925][ T3003] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 59.136453][ T3003] bridge0: port 1(bridge_slave_0) entered disabled state [ 59.144907][ T3003] bridge0: port 2(bridge_slave_1) entered disabled state [ 59.153422][ T3003] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 59.164405][ T8102] 8021q: adding VLAN 0 to HW filter on device team0 [ 59.175237][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 59.184198][ T3695] bridge0: port 1(bridge_slave_0) entered blocking state [ 59.191261][ T3695] bridge0: port 1(bridge_slave_0) entered forwarding state [ 59.210960][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 59.219731][ T3695] bridge0: port 2(bridge_slave_1) entered blocking state [ 59.226777][ T3695] bridge0: port 2(bridge_slave_1) entered forwarding state [ 59.236215][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 59.244557][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 59.253063][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 59.261691][ T3695] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 59.272736][ T22] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 59.282904][ T8102] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 59.298415][ T8102] 8021q: adding VLAN 0 to HW filter on device batadv0 2019/06/29 14:52:01 executed programs: 5 2019/06/29 14:52:07 executed programs: 11 [ 75.029458][ T8194] [ 75.031807][ T8194] ===================================================== [ 75.038814][ T8194] WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected [ 75.046463][ T8194] 5.2.0-rc6+ #10 Not tainted [ 75.051353][ T8194] ----------------------------------------------------- [ 75.058420][ T8194] syz-executor.0/8194 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 75.066644][ T8194] 00000000c6f58e60 (&ctx->fd_wqh){....}, at: io_submit_one+0x1167/0x1ac0 [ 75.075322][ T8194] [ 75.075322][ T8194] and this task is already holding: [ 75.083016][ T8194] 0000000072e36201 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0x1137/0x1ac0 [ 75.092729][ T8194] which would create a new lock dependency: [ 75.099000][ T8194] (&(&ctx->ctx_lock)->rlock){..-.} -> (&ctx->fd_wqh){....} [ 75.106630][ T8194] [ 75.106630][ T8194] but this new dependency connects a SOFTIRQ-irq-safe lock: [ 75.116503][ T8194] (&(&ctx->ctx_lock)->rlock){..-.} [ 75.116511][ T8194] [ 75.116511][ T8194] ... which became SOFTIRQ-irq-safe at: [ 75.129414][ T8194] _raw_spin_lock_irq+0x6a/0x80 [ 75.134693][ T8194] free_ioctx_users+0x33/0x1d0 [ 75.139549][ T8194] percpu_ref_put+0x1c6/0x1d0 [ 75.144301][ T8194] percpu_ref_switch_to_atomic_rcu+0x260/0x310 [ 75.150552][ T8194] rcu_core+0x8d6/0xf90 [ 75.154850][ T8194] __do_softirq+0x340/0x7b0 [ 75.159546][ T8194] irq_exit+0x21a/0x230 [ 75.163987][ T8194] smp_apic_timer_interrupt+0xf8/0x260 [ 75.169527][ T8194] apic_timer_interrupt+0xf/0x20 [ 75.174664][ T8194] native_safe_halt+0xe/0x10 [ 75.179326][ T8194] arch_cpu_idle+0xa/0x10 [ 75.183727][ T8194] do_idle+0x18a/0x760 [ 75.187871][ T8194] cpu_startup_entry+0x25/0x30 [ 75.192880][ T8194] start_secondary+0x425/0x4c0 [ 75.197721][ T8194] secondary_startup_64+0xa4/0xb0 [ 75.202810][ T8194] [ 75.202810][ T8194] to a SOFTIRQ-irq-unsafe lock: [ 75.209813][ T8194] (&ctx->fault_pending_wqh){+.+.} [ 75.209821][ T8194] [ 75.209821][ T8194] ... which became SOFTIRQ-irq-unsafe at: [ 75.222885][ T8194] ... [ 75.222904][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.230054][ T8194] userfaultfd_release+0x4dc/0x620 [ 75.235457][ T8194] __fput+0x2e4/0x740 [ 75.239580][ T8194] ____fput+0x15/0x20 [ 75.243870][ T8194] task_work_run+0x17e/0x1b0 [ 75.248708][ T8194] get_signal+0x2146/0x21f0 [ 75.253328][ T8194] do_signal+0x7b/0x750 [ 75.257612][ T8194] prepare_exit_to_usermode+0x2f5/0x4f0 [ 75.263278][ T8194] syscall_return_slowpath+0x110/0x440 [ 75.268851][ T8194] do_syscall_64+0x126/0x140 [ 75.273526][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.279488][ T8194] [ 75.279488][ T8194] other info that might help us debug this: [ 75.279488][ T8194] [ 75.289736][ T8194] Chain exists of: [ 75.289736][ T8194] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 75.289736][ T8194] [ 75.304287][ T8194] Possible interrupt unsafe locking scenario: [ 75.304287][ T8194] [ 75.312830][ T8194] CPU0 CPU1 [ 75.318185][ T8194] ---- ---- [ 75.323536][ T8194] lock(&ctx->fault_pending_wqh); [ 75.328631][ T8194] local_irq_disable(); [ 75.335408][ T8194] lock(&(&ctx->ctx_lock)->rlock); [ 75.343121][ T8194] lock(&ctx->fd_wqh); [ 75.349780][ T8194] [ 75.353220][ T8194] lock(&(&ctx->ctx_lock)->rlock); [ 75.358575][ T8194] [ 75.358575][ T8194] *** DEADLOCK *** [ 75.358575][ T8194] [ 75.366910][ T8194] 1 lock held by syz-executor.0/8194: [ 75.372262][ T8194] #0: 0000000072e36201 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0x1137/0x1ac0 [ 75.382188][ T8194] [ 75.382188][ T8194] the dependencies between SOFTIRQ-irq-safe lock and the holding lock: [ 75.392600][ T8194] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 75.398147][ T8194] IN-SOFTIRQ-W at: [ 75.402136][ T8194] _raw_spin_lock_irq+0x6a/0x80 [ 75.409034][ T8194] free_ioctx_users+0x33/0x1d0 [ 75.415649][ T8194] percpu_ref_put+0x1c6/0x1d0 [ 75.421975][ T8194] percpu_ref_switch_to_atomic_rcu+0x260/0x310 [ 75.429867][ T8194] rcu_core+0x8d6/0xf90 [ 75.436114][ T8194] __do_softirq+0x340/0x7b0 [ 75.442462][ T8194] irq_exit+0x21a/0x230 [ 75.448313][ T8194] smp_apic_timer_interrupt+0xf8/0x260 [ 75.455529][ T8194] apic_timer_interrupt+0xf/0x20 [ 75.462153][ T8194] native_safe_halt+0xe/0x10 [ 75.468397][ T8194] arch_cpu_idle+0xa/0x10 [ 75.474375][ T8194] do_idle+0x18a/0x760 [ 75.480093][ T8194] cpu_startup_entry+0x25/0x30 [ 75.486611][ T8194] start_secondary+0x425/0x4c0 [ 75.493151][ T8194] secondary_startup_64+0xa4/0xb0 [ 75.499822][ T8194] INITIAL USE at: [ 75.503807][ T8194] _raw_spin_lock_irq+0x6a/0x80 [ 75.510221][ T8194] free_ioctx_users+0x33/0x1d0 [ 75.516540][ T8194] percpu_ref_put+0x1c6/0x1d0 [ 75.522775][ T8194] percpu_ref_switch_to_atomic_rcu+0x260/0x310 [ 75.530595][ T8194] rcu_core+0x8d6/0xf90 [ 75.536311][ T8194] __do_softirq+0x340/0x7b0 [ 75.542570][ T8194] irq_exit+0x21a/0x230 [ 75.548405][ T8194] smp_apic_timer_interrupt+0xf8/0x260 [ 75.555449][ T8194] apic_timer_interrupt+0xf/0x20 [ 75.561997][ T8194] native_safe_halt+0xe/0x10 [ 75.568180][ T8194] arch_cpu_idle+0xa/0x10 [ 75.574862][ T8194] do_idle+0x18a/0x760 [ 75.580610][ T8194] cpu_startup_entry+0x25/0x30 [ 75.586947][ T8194] start_secondary+0x425/0x4c0 [ 75.593280][ T8194] secondary_startup_64+0xa4/0xb0 [ 75.600188][ T8194] } [ 75.602689][ T8194] ... key at: [] ioctx_alloc.__key+0x0/0x10 [ 75.610795][ T8194] ... acquired at: [ 75.614929][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.619603][ T8194] io_submit_one+0x1167/0x1ac0 [ 75.624595][ T8194] __se_sys_io_submit+0x18f/0x2d0 [ 75.629832][ T8194] __x64_sys_io_submit+0x7b/0x90 [ 75.635065][ T8194] do_syscall_64+0xfe/0x140 [ 75.639772][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.645825][ T8194] [ 75.648191][ T8194] [ 75.648191][ T8194] the dependencies between the lock to be acquired [ 75.648195][ T8194] and SOFTIRQ-irq-unsafe lock: [ 75.661970][ T8194] -> (&ctx->fault_pending_wqh){+.+.} { [ 75.667740][ T8194] HARDIRQ-ON-W at: [ 75.671812][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.678134][ T8194] userfaultfd_release+0x4dc/0x620 [ 75.685100][ T8194] __fput+0x2e4/0x740 [ 75.691056][ T8194] ____fput+0x15/0x20 [ 75.697169][ T8194] task_work_run+0x17e/0x1b0 [ 75.703877][ T8194] get_signal+0x2146/0x21f0 [ 75.710334][ T8194] do_signal+0x7b/0x750 [ 75.716575][ T8194] prepare_exit_to_usermode+0x2f5/0x4f0 [ 75.723992][ T8194] syscall_return_slowpath+0x110/0x440 [ 75.731279][ T8194] do_syscall_64+0x126/0x140 [ 75.737689][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.745387][ T8194] SOFTIRQ-ON-W at: [ 75.749528][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.755891][ T8194] userfaultfd_release+0x4dc/0x620 [ 75.762820][ T8194] __fput+0x2e4/0x740 [ 75.768697][ T8194] ____fput+0x15/0x20 [ 75.774906][ T8194] task_work_run+0x17e/0x1b0 [ 75.781371][ T8194] get_signal+0x2146/0x21f0 [ 75.787975][ T8194] do_signal+0x7b/0x750 [ 75.793956][ T8194] prepare_exit_to_usermode+0x2f5/0x4f0 [ 75.801325][ T8194] syscall_return_slowpath+0x110/0x440 [ 75.808748][ T8194] do_syscall_64+0x126/0x140 [ 75.815297][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.822996][ T8194] INITIAL USE at: [ 75.827091][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.833330][ T8194] userfaultfd_ctx_read+0x3e7/0x1430 [ 75.840384][ T8194] userfaultfd_read+0x15d/0x2b0 [ 75.847013][ T8194] __vfs_read+0xf9/0x7c0 [ 75.852999][ T8194] vfs_read+0x195/0x3c0 [ 75.858889][ T8194] ksys_read+0x16b/0x2a0 [ 75.864869][ T8194] __x64_sys_read+0x7b/0x90 [ 75.871111][ T8194] do_syscall_64+0xfe/0x140 [ 75.877470][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.885096][ T8194] } [ 75.887684][ T8194] ... key at: [] init_once_userfaultfd_ctx.__key+0x0/0x10 [ 75.896988][ T8194] ... acquired at: [ 75.900885][ T8194] _raw_spin_lock+0x2d/0x40 [ 75.905562][ T8194] userfaultfd_ctx_read+0x3e7/0x1430 [ 75.911111][ T8194] userfaultfd_read+0x15d/0x2b0 [ 75.916130][ T8194] __vfs_read+0xf9/0x7c0 [ 75.920661][ T8194] vfs_read+0x195/0x3c0 [ 75.925216][ T8194] ksys_read+0x16b/0x2a0 [ 75.929613][ T8194] __x64_sys_read+0x7b/0x90 [ 75.934284][ T8194] do_syscall_64+0xfe/0x140 [ 75.939002][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 75.945171][ T8194] [ 75.947482][ T8194] -> (&ctx->fd_wqh){....} { [ 75.951966][ T8194] INITIAL USE at: [ 75.956026][ T8194] _raw_spin_lock_irq+0x6a/0x80 [ 75.962596][ T8194] userfaultfd_ctx_read+0x198/0x1430 [ 75.969439][ T8194] userfaultfd_read+0x15d/0x2b0 [ 75.975854][ T8194] __vfs_read+0xf9/0x7c0 [ 75.981654][ T8194] vfs_read+0x195/0x3c0 [ 75.987371][ T8194] ksys_read+0x16b/0x2a0 [ 75.993168][ T8194] __x64_sys_read+0x7b/0x90 [ 75.999249][ T8194] do_syscall_64+0xfe/0x140 [ 76.005311][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 76.012749][ T8194] } [ 76.015243][ T8194] ... key at: [] init_once_userfaultfd_ctx.__key.15+0x0/0x10 [ 76.024764][ T8194] ... acquired at: [ 76.028566][ T8194] _raw_spin_lock+0x2d/0x40 [ 76.033233][ T8194] io_submit_one+0x1167/0x1ac0 [ 76.038321][ T8194] __se_sys_io_submit+0x18f/0x2d0 [ 76.043521][ T8194] __x64_sys_io_submit+0x7b/0x90 [ 76.048627][ T8194] do_syscall_64+0xfe/0x140 [ 76.053429][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 76.059610][ T8194] [ 76.061926][ T8194] [ 76.061926][ T8194] stack backtrace: [ 76.067946][ T8194] CPU: 0 PID: 8194 Comm: syz-executor.0 Not tainted 5.2.0-rc6+ #10 [ 76.075825][ T8194] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 76.095677][ T8194] Call Trace: [ 76.099015][ T8194] dump_stack+0x1d8/0x2f8 [ 76.103373][ T8194] validate_chain+0x829b/0x84f0 [ 76.108227][ T8194] ? match_held_lock+0x280/0x280 [ 76.113172][ T8194] ? match_held_lock+0x280/0x280 [ 76.118270][ T8194] ? pick_next_task_fair+0x124e/0x1bf0 [ 76.123961][ T8194] ? __bfs+0x550/0x550 [ 76.128034][ T8194] ? match_held_lock+0x280/0x280 [ 76.132973][ T8194] ? __lock_acquire+0xcf7/0x1a40 [ 76.138015][ T8194] ? trace_lock_acquire+0x190/0x190 [ 76.143216][ T8194] ? unwind_next_frame+0x415/0x870 [ 76.148407][ T8194] ? __bfs+0x550/0x550 [ 76.152516][ T8194] ? __bfs+0x550/0x550 [ 76.156648][ T8194] ? __bfs+0x550/0x550 [ 76.160718][ T8194] ? register_lock_class+0xde/0x1110 [ 76.166131][ T8194] ? arch_stack_walk+0x98/0xe0 [ 76.171002][ T8194] ? __bfs+0x550/0x550 [ 76.175389][ T8194] ? register_lock_class+0xde/0x1110 [ 76.180880][ T8194] ? __lock_acquire+0xcf7/0x1a40 [ 76.186045][ T8194] ? is_dynamic_key+0x1c0/0x1c0 [ 76.190941][ T8194] __lock_acquire+0xcf7/0x1a40 [ 76.195710][ T8194] ? trace_lock_acquire+0x190/0x190 [ 76.201188][ T8194] ? _raw_spin_unlock_irqrestore+0x77/0xe0 [ 76.206994][ T8194] ? kasan_check_write+0x14/0x20 [ 76.211919][ T8194] ? trace_lock_acquire+0x11c/0x190 [ 76.217114][ T8194] lock_acquire+0x158/0x250 [ 76.221619][ T8194] ? io_submit_one+0x1167/0x1ac0 [ 76.226587][ T8194] _raw_spin_lock+0x2d/0x40 [ 76.231128][ T8194] ? io_submit_one+0x1167/0x1ac0 [ 76.236065][ T8194] io_submit_one+0x1167/0x1ac0 [ 76.241004][ T8194] ? lookup_ioctx+0x6e0/0x6e0 [ 76.245721][ T8194] ? aio_poll_complete_work+0x500/0x500 [ 76.251284][ T8194] ? __might_fault+0x124/0x160 [ 76.256165][ T8194] __se_sys_io_submit+0x18f/0x2d0 [ 76.261198][ T8194] ? check_preemption_disabled+0xb7/0x280 [ 76.266928][ T8194] ? __x64_sys_io_submit+0x90/0x90 [ 76.272046][ T8194] ? debug_smp_processor_id+0x1c/0x20 [ 76.277426][ T8194] ? fpregs_assert_state_consistent+0xaa/0xe0 [ 76.283605][ T8194] ? prepare_exit_to_usermode+0x1e1/0x4f0 [ 76.289325][ T8194] ? __x64_sys_clock_gettime+0x1c5/0x220 [ 76.294956][ T8194] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 76.300449][ T8194] ? trace_irq_disable_rcuidle+0x23/0x1c0 [ 76.306269][ T8194] ? do_syscall_64+0x1d/0x140 [ 76.310981][ T8194] __x64_sys_io_submit+0x7b/0x90 [ 76.316051][ T8194] do_syscall_64+0xfe/0x140 [ 76.320554][ T8194] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 76.326475][ T8194] RIP: 0033:0x459519 [ 76.330364][ T8194] Code: fd b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 cb b7 fb ff c3 66 2e 0f 1f 84 00 00 00 00 [ 76.350222][ T8194] RSP: 002b:00007f446a3fdc78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1 [ 76.358621][ T8194] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000459519 [ 76.366592][ T8194] RDX: 0000000020000600 RSI: 0000000000000001 RDI: 00007f446a3ff000 [ 76.374751][ T8194] RBP: 000000000075bfc8 R08: 0000000000000000 R09: 0000000000000000 [ 76.383000][ T8194] R10: 0000000000000000 R11: 0000000000000246 R12: 00007f446a3fe6d4 [ 76.390979][ T8194] R13: 00000000004c0898 R14: 00000000004d3548 R15: 00000000ffffffff 2019/06/29 14:52:14 executed programs: 17 [ 76.494687][ T3879] kobject: 'loop0' (00000000ad2fcc99): kobject_uevent_env [ 76.501972][ T3879] kobject: 'loop0' (00000000ad2fcc99): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 77.443738][ T3879] kobject: 'loop0' (00000000ad2fcc99): kobject_uevent_env [ 77.451086][ T3879] kobject: 'loop0' (00000000ad2fcc99): fill_kobj_path: path = '/devices/virtual/block/loop0'