[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 71.214369][ T27] audit: type=1800 audit(1561131422.414:25): pid=8726 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 71.257028][ T27] audit: type=1800 audit(1561131422.424:26): pid=8726 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 71.306823][ T27] audit: type=1800 audit(1561131422.424:27): pid=8726 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.1.41' (ECDSA) to the list of known hosts. 2019/06/21 15:37:16 parsed 1 programs 2019/06/21 15:37:18 executed programs: 0 syzkaller login: [ 87.198005][ T8892] IPVS: ftp: loaded support on port[0] = 21 [ 87.262383][ T8892] chnl_net:caif_netlink_parms(): no params data found [ 87.291324][ T8892] bridge0: port 1(bridge_slave_0) entered blocking state [ 87.298992][ T8892] bridge0: port 1(bridge_slave_0) entered disabled state [ 87.315548][ T8892] device bridge_slave_0 entered promiscuous mode [ 87.323727][ T8892] bridge0: port 2(bridge_slave_1) entered blocking state [ 87.331262][ T8892] bridge0: port 2(bridge_slave_1) entered disabled state [ 87.338915][ T8892] device bridge_slave_1 entered promiscuous mode [ 87.355901][ T8892] bond0: Enslaving bond_slave_0 as an active interface with an up link [ 87.366292][ T8892] bond0: Enslaving bond_slave_1 as an active interface with an up link [ 87.385211][ T8892] team0: Port device team_slave_0 added [ 87.402602][ T8892] team0: Port device team_slave_1 added [ 87.469062][ T8892] device hsr_slave_0 entered promiscuous mode [ 87.527307][ T8892] device hsr_slave_1 entered promiscuous mode [ 87.604564][ T8892] bridge0: port 2(bridge_slave_1) entered blocking state [ 87.611761][ T8892] bridge0: port 2(bridge_slave_1) entered forwarding state [ 87.619664][ T8892] bridge0: port 1(bridge_slave_0) entered blocking state [ 87.626806][ T8892] bridge0: port 1(bridge_slave_0) entered forwarding state [ 87.662168][ T8892] 8021q: adding VLAN 0 to HW filter on device bond0 [ 87.675653][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 87.688701][ T12] bridge0: port 1(bridge_slave_0) entered disabled state [ 87.697440][ T12] bridge0: port 2(bridge_slave_1) entered disabled state [ 87.705347][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 87.718508][ T8892] 8021q: adding VLAN 0 to HW filter on device team0 [ 87.728667][ T3015] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 87.738199][ T3015] bridge0: port 1(bridge_slave_0) entered blocking state [ 87.745262][ T3015] bridge0: port 1(bridge_slave_0) entered forwarding state [ 87.769514][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 87.778125][ T12] bridge0: port 2(bridge_slave_1) entered blocking state [ 87.785164][ T12] bridge0: port 2(bridge_slave_1) entered forwarding state [ 87.793435][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 87.801915][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 87.810808][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 87.819057][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 87.828950][ T8892] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 87.836866][ T12] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 87.854808][ T8892] 8021q: adding VLAN 0 to HW filter on device batadv0 2019/06/21 15:37:23 executed programs: 5 2019/06/21 15:37:29 executed programs: 11 [ 102.727844][ T8978] [ 102.730477][ T8978] ===================================================== [ 102.738013][ T8978] WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected [ 102.745947][ T8978] 5.2.0-rc5+ #38 Not tainted [ 102.751549][ T8978] ----------------------------------------------------- [ 102.758564][ T8978] syz-executor.0/8978 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 102.766785][ T8978] 00000000caa414bf (&ctx->fd_wqh){....}, at: io_submit_one+0xefa/0x2ef0 [ 102.775907][ T8978] [ 102.775907][ T8978] and this task is already holding: [ 102.783499][ T8978] 00000000eb6cecbf (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 102.793153][ T8978] which would create a new lock dependency: [ 102.799424][ T8978] (&(&ctx->ctx_lock)->rlock){..-.} -> (&ctx->fd_wqh){....} [ 102.807420][ T8978] [ 102.807420][ T8978] but this new dependency connects a SOFTIRQ-irq-safe lock: [ 102.817302][ T8978] (&(&ctx->ctx_lock)->rlock){..-.} [ 102.817312][ T8978] [ 102.817312][ T8978] ... which became SOFTIRQ-irq-safe at: [ 102.830592][ T8978] lock_acquire+0x16f/0x3f0 [ 102.835213][ T8978] _raw_spin_lock_irq+0x60/0x80 [ 102.840265][ T8978] free_ioctx_users+0x2d/0x490 [ 102.845417][ T8978] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 102.852021][ T8978] rcu_core+0xba5/0x1500 [ 102.856813][ T8978] __do_softirq+0x25c/0x94c [ 102.861437][ T8978] irq_exit+0x180/0x1d0 [ 102.865680][ T8978] smp_apic_timer_interrupt+0x13b/0x550 [ 102.872023][ T8978] apic_timer_interrupt+0xf/0x20 [ 102.877329][ T8978] native_safe_halt+0xe/0x10 [ 102.882212][ T8978] arch_cpu_idle+0xa/0x10 [ 102.886882][ T8978] default_idle_call+0x36/0x90 [ 102.891833][ T8978] do_idle+0x377/0x560 [ 102.895988][ T8978] cpu_startup_entry+0x1b/0x20 [ 102.901022][ T8978] start_secondary+0x34e/0x4c0 [ 102.905878][ T8978] secondary_startup_64+0xa4/0xb0 [ 102.911112][ T8978] [ 102.911112][ T8978] to a SOFTIRQ-irq-unsafe lock: [ 102.918373][ T8978] (&ctx->fault_pending_wqh){+.+.} [ 102.918381][ T8978] [ 102.918381][ T8978] ... which became SOFTIRQ-irq-unsafe at: [ 102.931658][ T8978] ... [ 102.931678][ T8978] lock_acquire+0x16f/0x3f0 [ 102.939479][ T8978] _raw_spin_lock+0x2f/0x40 [ 102.944152][ T8978] userfaultfd_release+0x4ca/0x710 [ 102.949471][ T8978] __fput+0x2ff/0x890 [ 102.953866][ T8978] ____fput+0x16/0x20 [ 102.958058][ T8978] task_work_run+0x145/0x1c0 [ 102.962877][ T8978] get_signal+0x201b/0x24b0 [ 102.967461][ T8978] do_signal+0x87/0x1900 [ 102.971992][ T8978] exit_to_usermode_loop+0x244/0x2c0 [ 102.977365][ T8978] do_syscall_64+0x58e/0x680 [ 102.982252][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 102.988494][ T8978] [ 102.988494][ T8978] other info that might help us debug this: [ 102.988494][ T8978] [ 102.999066][ T8978] Chain exists of: [ 102.999066][ T8978] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 102.999066][ T8978] [ 103.014163][ T8978] Possible interrupt unsafe locking scenario: [ 103.014163][ T8978] [ 103.023078][ T8978] CPU0 CPU1 [ 103.028592][ T8978] ---- ---- [ 103.034354][ T8978] lock(&ctx->fault_pending_wqh); [ 103.039462][ T8978] local_irq_disable(); [ 103.046226][ T8978] lock(&(&ctx->ctx_lock)->rlock); [ 103.054792][ T8978] lock(&ctx->fd_wqh); [ 103.061462][ T8978] [ 103.064911][ T8978] lock(&(&ctx->ctx_lock)->rlock); [ 103.070519][ T8978] [ 103.070519][ T8978] *** DEADLOCK *** [ 103.070519][ T8978] [ 103.079094][ T8978] 1 lock held by syz-executor.0/8978: [ 103.084877][ T8978] #0: 00000000eb6cecbf (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 103.095270][ T8978] [ 103.095270][ T8978] the dependencies between SOFTIRQ-irq-safe lock and the holding lock: [ 103.106276][ T8978] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 103.111953][ T8978] IN-SOFTIRQ-W at: [ 103.115993][ T8978] lock_acquire+0x16f/0x3f0 [ 103.122929][ T8978] _raw_spin_lock_irq+0x60/0x80 [ 103.129770][ T8978] free_ioctx_users+0x2d/0x490 [ 103.136187][ T8978] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 103.144127][ T8978] rcu_core+0xba5/0x1500 [ 103.150580][ T8978] __do_softirq+0x25c/0x94c [ 103.157495][ T8978] irq_exit+0x180/0x1d0 [ 103.163438][ T8978] smp_apic_timer_interrupt+0x13b/0x550 [ 103.170855][ T8978] apic_timer_interrupt+0xf/0x20 [ 103.177438][ T8978] native_safe_halt+0xe/0x10 [ 103.184041][ T8978] arch_cpu_idle+0xa/0x10 [ 103.190202][ T8978] default_idle_call+0x36/0x90 [ 103.197191][ T8978] do_idle+0x377/0x560 [ 103.203173][ T8978] cpu_startup_entry+0x1b/0x20 [ 103.209850][ T8978] start_secondary+0x34e/0x4c0 [ 103.216638][ T8978] secondary_startup_64+0xa4/0xb0 [ 103.223405][ T8978] INITIAL USE at: [ 103.227592][ T8978] lock_acquire+0x16f/0x3f0 [ 103.238908][ T8978] _raw_spin_lock_irq+0x60/0x80 [ 103.245507][ T8978] free_ioctx_users+0x2d/0x490 [ 103.251952][ T8978] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 103.260218][ T8978] rcu_core+0xba5/0x1500 [ 103.266026][ T8978] __do_softirq+0x25c/0x94c [ 103.272091][ T8978] irq_exit+0x180/0x1d0 [ 103.279096][ T8978] smp_apic_timer_interrupt+0x13b/0x550 [ 103.286433][ T8978] apic_timer_interrupt+0xf/0x20 [ 103.293507][ T8978] native_safe_halt+0xe/0x10 [ 103.299823][ T8978] arch_cpu_idle+0xa/0x10 [ 103.305722][ T8978] default_idle_call+0x36/0x90 [ 103.312585][ T8978] do_idle+0x377/0x560 [ 103.318217][ T8978] cpu_startup_entry+0x1b/0x20 [ 103.325210][ T8978] start_secondary+0x34e/0x4c0 [ 103.331933][ T8978] secondary_startup_64+0xa4/0xb0 [ 103.338511][ T8978] } [ 103.341173][ T8978] ... key at: [] __key.53435+0x0/0x40 [ 103.348769][ T8978] ... acquired at: [ 103.352766][ T8978] lock_acquire+0x16f/0x3f0 [ 103.357621][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.362464][ T8978] io_submit_one+0xefa/0x2ef0 [ 103.368185][ T8978] __x64_sys_io_submit+0x1bd/0x570 [ 103.373993][ T8978] do_syscall_64+0xfd/0x680 [ 103.378669][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.398238][ T8978] [ 103.400758][ T8978] [ 103.400758][ T8978] the dependencies between the lock to be acquired [ 103.400762][ T8978] and SOFTIRQ-irq-unsafe lock: [ 103.415220][ T8978] -> (&ctx->fault_pending_wqh){+.+.} { [ 103.421089][ T8978] HARDIRQ-ON-W at: [ 103.425648][ T8978] lock_acquire+0x16f/0x3f0 [ 103.431973][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.438310][ T8978] userfaultfd_release+0x4ca/0x710 [ 103.445492][ T8978] __fput+0x2ff/0x890 [ 103.451342][ T8978] ____fput+0x16/0x20 [ 103.457654][ T8978] task_work_run+0x145/0x1c0 [ 103.464690][ T8978] get_signal+0x201b/0x24b0 [ 103.471258][ T8978] do_signal+0x87/0x1900 [ 103.477925][ T8978] exit_to_usermode_loop+0x244/0x2c0 [ 103.485535][ T8978] do_syscall_64+0x58e/0x680 [ 103.492495][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.500207][ T8978] SOFTIRQ-ON-W at: [ 103.504298][ T8978] lock_acquire+0x16f/0x3f0 [ 103.510622][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.516942][ T8978] userfaultfd_release+0x4ca/0x710 [ 103.524197][ T8978] __fput+0x2ff/0x890 [ 103.530373][ T8978] ____fput+0x16/0x20 [ 103.536681][ T8978] task_work_run+0x145/0x1c0 [ 103.543796][ T8978] get_signal+0x201b/0x24b0 [ 103.550445][ T8978] do_signal+0x87/0x1900 [ 103.556719][ T8978] exit_to_usermode_loop+0x244/0x2c0 [ 103.564159][ T8978] do_syscall_64+0x58e/0x680 [ 103.571350][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.579734][ T8978] INITIAL USE at: [ 103.583718][ T8978] lock_acquire+0x16f/0x3f0 [ 103.591252][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.597648][ T8978] userfaultfd_read+0x540/0x1940 [ 103.605113][ T8978] __vfs_read+0x8a/0x110 [ 103.611863][ T8978] vfs_read+0x194/0x3e0 [ 103.618216][ T8978] ksys_read+0x14f/0x290 [ 103.625099][ T8978] __x64_sys_read+0x73/0xb0 [ 103.632167][ T8978] do_syscall_64+0xfd/0x680 [ 103.639074][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.647893][ T8978] } [ 103.650514][ T8978] ... key at: [] __key.46108+0x0/0x40 [ 103.659287][ T8978] ... acquired at: [ 103.663454][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.668992][ T8978] userfaultfd_read+0x540/0x1940 [ 103.674611][ T8978] __vfs_read+0x8a/0x110 [ 103.679477][ T8978] vfs_read+0x194/0x3e0 [ 103.684301][ T8978] ksys_read+0x14f/0x290 [ 103.689298][ T8978] __x64_sys_read+0x73/0xb0 [ 103.694629][ T8978] do_syscall_64+0xfd/0x680 [ 103.699765][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.706313][ T8978] [ 103.708878][ T8978] -> (&ctx->fd_wqh){....} { [ 103.713472][ T8978] INITIAL USE at: [ 103.717853][ T8978] lock_acquire+0x16f/0x3f0 [ 103.724864][ T8978] _raw_spin_lock_irq+0x60/0x80 [ 103.731637][ T8978] userfaultfd_read+0x27a/0x1940 [ 103.738381][ T8978] __vfs_read+0x8a/0x110 [ 103.744213][ T8978] vfs_read+0x194/0x3e0 [ 103.751140][ T8978] ksys_read+0x14f/0x290 [ 103.757328][ T8978] __x64_sys_read+0x73/0xb0 [ 103.763673][ T8978] do_syscall_64+0xfd/0x680 [ 103.770388][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.778565][ T8978] } [ 103.781175][ T8978] ... key at: [] __key.46111+0x0/0x40 [ 103.789398][ T8978] ... acquired at: [ 103.793310][ T8978] lock_acquire+0x16f/0x3f0 [ 103.798190][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.803300][ T8978] io_submit_one+0xefa/0x2ef0 [ 103.809091][ T8978] __x64_sys_io_submit+0x1bd/0x570 [ 103.814577][ T8978] do_syscall_64+0xfd/0x680 [ 103.819516][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 103.826119][ T8978] [ 103.828717][ T8978] [ 103.828717][ T8978] stack backtrace: [ 103.835224][ T8978] CPU: 1 PID: 8978 Comm: syz-executor.0 Not tainted 5.2.0-rc5+ #38 [ 103.844055][ T8978] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 103.855414][ T8978] Call Trace: [ 103.858757][ T8978] dump_stack+0x172/0x1f0 [ 103.863435][ T8978] check_irq_usage.cold+0x711/0xba0 [ 103.868651][ T8978] ? check_usage_forwards+0x370/0x370 [ 103.874659][ T8978] ? is_dynamic_key+0x1c0/0x1c0 [ 103.880103][ T8978] ? __lock_acquire+0x54f/0x5490 [ 103.885463][ T8978] ? graph_lock+0x7b/0x200 [ 103.889986][ T8978] ? is_dynamic_key+0x1c0/0x1c0 [ 103.895353][ T8978] __lock_acquire+0x2469/0x5490 [ 103.900681][ T8978] ? __lock_acquire+0x2469/0x5490 [ 103.906574][ T8978] ? mark_held_locks+0xf0/0xf0 [ 103.911874][ T8978] ? find_held_lock+0x35/0x130 [ 103.917240][ T8978] ? mark_held_locks+0xf0/0xf0 [ 103.922330][ T8978] ? kasan_check_write+0x14/0x20 [ 103.927790][ T8978] ? _raw_spin_unlock_irqrestore+0x6b/0xe0 [ 103.934094][ T8978] ? add_wait_queue+0x112/0x170 [ 103.939429][ T8978] ? lockdep_hardirqs_on+0x418/0x5d0 [ 103.944733][ T8978] ? trace_hardirqs_on+0x67/0x220 [ 103.950004][ T8978] ? kasan_check_read+0x11/0x20 [ 103.955667][ T8978] lock_acquire+0x16f/0x3f0 [ 103.960352][ T8978] ? io_submit_one+0xefa/0x2ef0 [ 103.965347][ T8978] _raw_spin_lock+0x2f/0x40 [ 103.969861][ T8978] ? io_submit_one+0xefa/0x2ef0 [ 103.975865][ T8978] io_submit_one+0xefa/0x2ef0 [ 103.980569][ T8978] ? mark_held_locks+0xf0/0xf0 [ 103.985635][ T8978] ? ioctx_alloc+0x1db0/0x1db0 [ 103.991355][ T8978] ? __might_fault+0x12b/0x1e0 [ 103.996482][ T8978] ? aio_setup_rw+0x180/0x180 [ 104.001784][ T8978] __x64_sys_io_submit+0x1bd/0x570 [ 104.007383][ T8978] ? __x64_sys_io_submit+0x1bd/0x570 [ 104.013281][ T8978] ? __ia32_sys_io_destroy+0x420/0x420 [ 104.019126][ T8978] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 104.025181][ T8978] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 104.031240][ T8978] ? do_syscall_64+0x26/0x680 [ 104.036514][ T8978] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 104.042849][ T8978] ? do_syscall_64+0x26/0x680 [ 104.047534][ T8978] ? lockdep_hardirqs_on+0x418/0x5d0 [ 104.053369][ T8978] do_syscall_64+0xfd/0x680 [ 104.058555][ T8978] ? do_syscall_64+0xfd/0x680 [ 104.064132][ T8978] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 104.070347][ T8978] RIP: 0033:0x4592c9 [ 104.074442][ T8978] 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 [ 104.094974][ T8978] RSP: 002b:00007ff60554bc78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1 [ 104.103585][ T8978] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004592c9 [ 104.112553][ T8978] RDX: 0000000020000600 RSI: 0000000000000001 RDI: 00007ff60554d000 [ 104.121012][ T8978] RBP: 000000000075bfc8 R08: 0000000000000000 R09: 0000000000000000 [ 104.129407][ T8978] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ff60554c6d4 [ 104.138274][ T8978] R13: 00000000004c0645 R14: 00000000004d3008 R15: 00000000ffffffff 2019/06/21 15:37:35 executed programs: 16 [ 104.242691][ T3879] kobject: 'loop0' (00000000dd90b32f): kobject_uevent_env [ 104.250024][ T3879] kobject: 'loop0' (00000000dd90b32f): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 105.152250][ T3879] kobject: 'loop0' (00000000dd90b32f): kobject_uevent_env [ 105.159866][ T3879] kobject: 'loop0' (00000000dd90b32f): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 106.063243][ T3879] kobject: 'loop0' (00000000dd90b32f): kobject_uevent_env [ 106.070775][ T3879] kobject: 'loop0' (00000000dd90b32f): fill_kobj_path: path = '/devices/virtual/block/loop0'