[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 56.733027][ T26] audit: type=1800 audit(1561150808.555:25): pid=8597 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 56.770880][ T26] audit: type=1800 audit(1561150808.555:26): pid=8597 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 56.827209][ T26] audit: type=1800 audit(1561150808.555:27): pid=8597 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.46' (ECDSA) to the list of known hosts. 2019/06/21 21:00:21 parsed 1 programs 2019/06/21 21:00:23 executed programs: 0 syzkaller login: [ 71.252137][ T8766] IPVS: ftp: loaded support on port[0] = 21 [ 71.312734][ T8766] chnl_net:caif_netlink_parms(): no params data found [ 71.338420][ T8766] bridge0: port 1(bridge_slave_0) entered blocking state [ 71.346693][ T8766] bridge0: port 1(bridge_slave_0) entered disabled state [ 71.354425][ T8766] device bridge_slave_0 entered promiscuous mode [ 71.362420][ T8766] bridge0: port 2(bridge_slave_1) entered blocking state [ 71.369484][ T8766] bridge0: port 2(bridge_slave_1) entered disabled state [ 71.377292][ T8766] device bridge_slave_1 entered promiscuous mode [ 71.393950][ T8766] bond0: Enslaving bond_slave_0 as an active interface with an up link [ 71.403679][ T8766] bond0: Enslaving bond_slave_1 as an active interface with an up link [ 71.420442][ T8766] team0: Port device team_slave_0 added [ 71.427786][ T8766] team0: Port device team_slave_1 added [ 71.503034][ T8766] device hsr_slave_0 entered promiscuous mode [ 71.571010][ T8766] device hsr_slave_1 entered promiscuous mode [ 71.669308][ T8766] bridge0: port 2(bridge_slave_1) entered blocking state [ 71.676512][ T8766] bridge0: port 2(bridge_slave_1) entered forwarding state [ 71.684360][ T8766] bridge0: port 1(bridge_slave_0) entered blocking state [ 71.691479][ T8766] bridge0: port 1(bridge_slave_0) entered forwarding state [ 71.726003][ T8766] 8021q: adding VLAN 0 to HW filter on device bond0 [ 71.737175][ T2501] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 71.757187][ T2501] bridge0: port 1(bridge_slave_0) entered disabled state [ 71.765754][ T2501] bridge0: port 2(bridge_slave_1) entered disabled state [ 71.775535][ T2501] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 71.789596][ T8766] 8021q: adding VLAN 0 to HW filter on device team0 [ 71.800103][ T2994] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 71.808744][ T2994] bridge0: port 1(bridge_slave_0) entered blocking state [ 71.815800][ T2994] bridge0: port 1(bridge_slave_0) entered forwarding state [ 71.826737][ T2501] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 71.835877][ T2501] bridge0: port 2(bridge_slave_1) entered blocking state [ 71.843016][ T2501] bridge0: port 2(bridge_slave_1) entered forwarding state [ 71.863739][ T2994] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 71.872862][ T2994] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 71.881635][ T2994] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 71.890072][ T2994] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 71.902169][ T2501] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 71.912696][ T8766] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 71.929641][ T8766] 8021q: adding VLAN 0 to HW filter on device batadv0 2019/06/21 21:00:28 executed programs: 5 2019/06/21 21:00:34 executed programs: 11 [ 85.867077][ T8848] [ 85.869629][ T8848] ===================================================== [ 85.876556][ T8848] WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected [ 85.884402][ T8848] 5.2.0-rc5+ #38 Not tainted [ 85.889083][ T8848] ----------------------------------------------------- [ 85.896028][ T8848] syz-executor.0/8848 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 85.904458][ T8848] 00000000c4a2beff (&ctx->fd_wqh){....}, at: io_submit_one+0xefa/0x2ef0 [ 85.913258][ T8848] [ 85.913258][ T8848] and this task is already holding: [ 85.920990][ T8848] 000000000c729560 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 85.930752][ T8848] which would create a new lock dependency: [ 85.936653][ T8848] (&(&ctx->ctx_lock)->rlock){..-.} -> (&ctx->fd_wqh){....} [ 85.943943][ T8848] [ 85.943943][ T8848] but this new dependency connects a SOFTIRQ-irq-safe lock: [ 85.953616][ T8848] (&(&ctx->ctx_lock)->rlock){..-.} [ 85.953626][ T8848] [ 85.953626][ T8848] ... which became SOFTIRQ-irq-safe at: [ 85.966817][ T8848] lock_acquire+0x16f/0x3f0 [ 85.971462][ T8848] _raw_spin_lock_irq+0x60/0x80 [ 85.976408][ T8848] free_ioctx_users+0x2d/0x490 [ 85.982031][ T8848] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 85.988276][ T8848] rcu_core+0xba5/0x1500 [ 85.992801][ T8848] __do_softirq+0x25c/0x94c [ 85.997397][ T8848] irq_exit+0x180/0x1d0 [ 86.001647][ T8848] smp_apic_timer_interrupt+0x13b/0x550 [ 86.007386][ T8848] apic_timer_interrupt+0xf/0x20 [ 86.012411][ T8848] native_safe_halt+0xe/0x10 [ 86.017089][ T8848] arch_cpu_idle+0xa/0x10 [ 86.021505][ T8848] default_idle_call+0x36/0x90 [ 86.026373][ T8848] do_idle+0x377/0x560 [ 86.030643][ T8848] cpu_startup_entry+0x1b/0x20 [ 86.035500][ T8848] start_secondary+0x34e/0x4c0 [ 86.040455][ T8848] secondary_startup_64+0xa4/0xb0 [ 86.045550][ T8848] [ 86.045550][ T8848] to a SOFTIRQ-irq-unsafe lock: [ 86.052875][ T8848] (&ctx->fault_pending_wqh){+.+.} [ 86.052885][ T8848] [ 86.052885][ T8848] ... which became SOFTIRQ-irq-unsafe at: [ 86.065863][ T8848] ... [ 86.065885][ T8848] lock_acquire+0x16f/0x3f0 [ 86.075438][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.080791][ T8848] userfaultfd_release+0x4ca/0x710 [ 86.086522][ T8848] __fput+0x2ff/0x890 [ 86.090878][ T8848] ____fput+0x16/0x20 [ 86.095212][ T8848] task_work_run+0x145/0x1c0 [ 86.102804][ T8848] get_signal+0x201b/0x24b0 [ 86.110056][ T8848] do_signal+0x87/0x1900 [ 86.115112][ T8848] exit_to_usermode_loop+0x244/0x2c0 [ 86.120591][ T8848] do_syscall_64+0x58e/0x680 [ 86.125401][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.131965][ T8848] [ 86.131965][ T8848] other info that might help us debug this: [ 86.131965][ T8848] [ 86.143215][ T8848] Chain exists of: [ 86.143215][ T8848] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 86.143215][ T8848] [ 86.159416][ T8848] Possible interrupt unsafe locking scenario: [ 86.159416][ T8848] [ 86.168613][ T8848] CPU0 CPU1 [ 86.174225][ T8848] ---- ---- [ 86.179898][ T8848] lock(&ctx->fault_pending_wqh); [ 86.185465][ T8848] local_irq_disable(); [ 86.193489][ T8848] lock(&(&ctx->ctx_lock)->rlock); [ 86.202622][ T8848] lock(&ctx->fd_wqh); [ 86.209409][ T8848] [ 86.212971][ T8848] lock(&(&ctx->ctx_lock)->rlock); [ 86.219001][ T8848] [ 86.219001][ T8848] *** DEADLOCK *** [ 86.219001][ T8848] [ 86.227719][ T8848] 1 lock held by syz-executor.0/8848: [ 86.233092][ T8848] #0: 000000000c729560 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 86.244144][ T8848] [ 86.244144][ T8848] the dependencies between SOFTIRQ-irq-safe lock and the holding lock: [ 86.255413][ T8848] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 86.264899][ T8848] IN-SOFTIRQ-W at: [ 86.269078][ T8848] lock_acquire+0x16f/0x3f0 [ 86.275264][ T8848] _raw_spin_lock_irq+0x60/0x80 [ 86.281804][ T8848] free_ioctx_users+0x2d/0x490 [ 86.288305][ T8848] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 86.296351][ T8848] rcu_core+0xba5/0x1500 [ 86.302939][ T8848] __do_softirq+0x25c/0x94c [ 86.309388][ T8848] irq_exit+0x180/0x1d0 [ 86.315328][ T8848] smp_apic_timer_interrupt+0x13b/0x550 [ 86.323130][ T8848] apic_timer_interrupt+0xf/0x20 [ 86.329815][ T8848] native_safe_halt+0xe/0x10 [ 86.336145][ T8848] arch_cpu_idle+0xa/0x10 [ 86.342130][ T8848] default_idle_call+0x36/0x90 [ 86.348530][ T8848] do_idle+0x377/0x560 [ 86.354410][ T8848] cpu_startup_entry+0x1b/0x20 [ 86.360849][ T8848] start_secondary+0x34e/0x4c0 [ 86.367347][ T8848] secondary_startup_64+0xa4/0xb0 [ 86.374094][ T8848] INITIAL USE at: [ 86.378247][ T8848] lock_acquire+0x16f/0x3f0 [ 86.384300][ T8848] _raw_spin_lock_irq+0x60/0x80 [ 86.390697][ T8848] free_ioctx_users+0x2d/0x490 [ 86.398068][ T8848] percpu_ref_switch_to_atomic_rcu+0x407/0x540 [ 86.405773][ T8848] rcu_core+0xba5/0x1500 [ 86.411711][ T8848] __do_softirq+0x25c/0x94c [ 86.417762][ T8848] irq_exit+0x180/0x1d0 [ 86.423512][ T8848] smp_apic_timer_interrupt+0x13b/0x550 [ 86.430720][ T8848] apic_timer_interrupt+0xf/0x20 [ 86.437279][ T8848] native_safe_halt+0xe/0x10 [ 86.444398][ T8848] arch_cpu_idle+0xa/0x10 [ 86.450340][ T8848] default_idle_call+0x36/0x90 [ 86.456751][ T8848] do_idle+0x377/0x560 [ 86.462480][ T8848] cpu_startup_entry+0x1b/0x20 [ 86.468842][ T8848] start_secondary+0x34e/0x4c0 [ 86.475152][ T8848] secondary_startup_64+0xa4/0xb0 [ 86.481713][ T8848] } [ 86.484207][ T8848] ... key at: [] __key.53435+0x0/0x40 [ 86.491634][ T8848] ... acquired at: [ 86.495428][ T8848] lock_acquire+0x16f/0x3f0 [ 86.500088][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.504748][ T8848] io_submit_one+0xefa/0x2ef0 [ 86.509630][ T8848] __x64_sys_io_submit+0x1bd/0x570 [ 86.514902][ T8848] do_syscall_64+0xfd/0x680 [ 86.519608][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.526293][ T8848] [ 86.528603][ T8848] [ 86.528603][ T8848] the dependencies between the lock to be acquired [ 86.528607][ T8848] and SOFTIRQ-irq-unsafe lock: [ 86.542216][ T8848] -> (&ctx->fault_pending_wqh){+.+.} { [ 86.547822][ T8848] HARDIRQ-ON-W at: [ 86.551931][ T8848] lock_acquire+0x16f/0x3f0 [ 86.558267][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.564624][ T8848] userfaultfd_release+0x4ca/0x710 [ 86.571595][ T8848] __fput+0x2ff/0x890 [ 86.577500][ T8848] ____fput+0x16/0x20 [ 86.583304][ T8848] task_work_run+0x145/0x1c0 [ 86.589750][ T8848] get_signal+0x201b/0x24b0 [ 86.596126][ T8848] do_signal+0x87/0x1900 [ 86.602223][ T8848] exit_to_usermode_loop+0x244/0x2c0 [ 86.609364][ T8848] do_syscall_64+0x58e/0x680 [ 86.615848][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.623691][ T8848] SOFTIRQ-ON-W at: [ 86.627789][ T8848] lock_acquire+0x16f/0x3f0 [ 86.634139][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.640494][ T8848] userfaultfd_release+0x4ca/0x710 [ 86.647409][ T8848] __fput+0x2ff/0x890 [ 86.653310][ T8848] ____fput+0x16/0x20 [ 86.659814][ T8848] task_work_run+0x145/0x1c0 [ 86.666211][ T8848] get_signal+0x201b/0x24b0 [ 86.672528][ T8848] do_signal+0x87/0x1900 [ 86.678762][ T8848] exit_to_usermode_loop+0x244/0x2c0 [ 86.685847][ T8848] do_syscall_64+0x58e/0x680 [ 86.692285][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.700113][ T8848] INITIAL USE at: [ 86.704081][ T8848] lock_acquire+0x16f/0x3f0 [ 86.710367][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.716649][ T8848] userfaultfd_read+0x540/0x1940 [ 86.723311][ T8848] __vfs_read+0x8a/0x110 [ 86.729378][ T8848] vfs_read+0x194/0x3e0 [ 86.735255][ T8848] ksys_read+0x14f/0x290 [ 86.741267][ T8848] __x64_sys_read+0x73/0xb0 [ 86.747533][ T8848] do_syscall_64+0xfd/0x680 [ 86.753929][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.761632][ T8848] } [ 86.764279][ T8848] ... key at: [] __key.46108+0x0/0x40 [ 86.771870][ T8848] ... acquired at: [ 86.775859][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.780521][ T8848] userfaultfd_read+0x540/0x1940 [ 86.785617][ T8848] __vfs_read+0x8a/0x110 [ 86.790135][ T8848] vfs_read+0x194/0x3e0 [ 86.794515][ T8848] ksys_read+0x14f/0x290 [ 86.798930][ T8848] __x64_sys_read+0x73/0xb0 [ 86.803593][ T8848] do_syscall_64+0xfd/0x680 [ 86.808508][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.814545][ T8848] [ 86.816855][ T8848] -> (&ctx->fd_wqh){....} { [ 86.821346][ T8848] INITIAL USE at: [ 86.825289][ T8848] lock_acquire+0x16f/0x3f0 [ 86.831343][ T8848] _raw_spin_lock_irq+0x60/0x80 [ 86.837737][ T8848] userfaultfd_read+0x27a/0x1940 [ 86.844239][ T8848] __vfs_read+0x8a/0x110 [ 86.850088][ T8848] vfs_read+0x194/0x3e0 [ 86.855794][ T8848] ksys_read+0x14f/0x290 [ 86.861641][ T8848] __x64_sys_read+0x73/0xb0 [ 86.867976][ T8848] do_syscall_64+0xfd/0x680 [ 86.874027][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.881584][ T8848] } [ 86.884083][ T8848] ... key at: [] __key.46111+0x0/0x40 [ 86.891680][ T8848] ... acquired at: [ 86.895488][ T8848] lock_acquire+0x16f/0x3f0 [ 86.900192][ T8848] _raw_spin_lock+0x2f/0x40 [ 86.904958][ T8848] io_submit_one+0xefa/0x2ef0 [ 86.909798][ T8848] __x64_sys_io_submit+0x1bd/0x570 [ 86.915183][ T8848] do_syscall_64+0xfd/0x680 [ 86.919908][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 86.925955][ T8848] [ 86.928295][ T8848] [ 86.928295][ T8848] stack backtrace: [ 86.934170][ T8848] CPU: 0 PID: 8848 Comm: syz-executor.0 Not tainted 5.2.0-rc5+ #38 [ 86.942043][ T8848] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 86.952141][ T8848] Call Trace: [ 86.955427][ T8848] dump_stack+0x172/0x1f0 [ 86.959786][ T8848] check_irq_usage.cold+0x711/0xba0 [ 86.965036][ T8848] ? check_usage_forwards+0x370/0x370 [ 86.970399][ T8848] ? is_dynamic_key+0x1c0/0x1c0 [ 86.975249][ T8848] ? __lock_acquire+0x54f/0x5490 [ 86.980406][ T8848] ? graph_lock+0x7b/0x200 [ 86.984893][ T8848] ? is_dynamic_key+0x1c0/0x1c0 [ 86.989962][ T8848] __lock_acquire+0x2469/0x5490 [ 86.994800][ T8848] ? __lock_acquire+0x2469/0x5490 [ 86.999806][ T8848] ? mark_held_locks+0xf0/0xf0 [ 87.004821][ T8848] ? find_held_lock+0x35/0x130 [ 87.009659][ T8848] ? mark_held_locks+0xf0/0xf0 [ 87.014465][ T8848] ? kasan_check_write+0x14/0x20 [ 87.019394][ T8848] ? _raw_spin_unlock_irqrestore+0x6b/0xe0 [ 87.025195][ T8848] ? add_wait_queue+0x112/0x170 [ 87.030033][ T8848] ? lockdep_hardirqs_on+0x418/0x5d0 [ 87.035395][ T8848] ? trace_hardirqs_on+0x67/0x220 [ 87.040405][ T8848] ? kasan_check_read+0x11/0x20 [ 87.045244][ T8848] lock_acquire+0x16f/0x3f0 [ 87.049777][ T8848] ? io_submit_one+0xefa/0x2ef0 [ 87.054650][ T8848] _raw_spin_lock+0x2f/0x40 [ 87.059145][ T8848] ? io_submit_one+0xefa/0x2ef0 [ 87.063973][ T8848] io_submit_one+0xefa/0x2ef0 [ 87.068637][ T8848] ? mark_held_locks+0xf0/0xf0 [ 87.073549][ T8848] ? ioctx_alloc+0x1db0/0x1db0 [ 87.078307][ T8848] ? __might_fault+0x12b/0x1e0 [ 87.083064][ T8848] ? aio_setup_rw+0x180/0x180 [ 87.087888][ T8848] __x64_sys_io_submit+0x1bd/0x570 [ 87.093066][ T8848] ? __x64_sys_io_submit+0x1bd/0x570 [ 87.098345][ T8848] ? __ia32_sys_io_destroy+0x420/0x420 [ 87.103794][ T8848] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 87.109860][ T8848] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 87.115439][ T8848] ? do_syscall_64+0x26/0x680 [ 87.120148][ T8848] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 87.126205][ T8848] ? do_syscall_64+0x26/0x680 [ 87.131155][ T8848] ? lockdep_hardirqs_on+0x418/0x5d0 [ 87.137161][ T8848] do_syscall_64+0xfd/0x680 [ 87.141807][ T8848] ? do_syscall_64+0xfd/0x680 [ 87.146527][ T8848] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 87.152504][ T8848] RIP: 0033:0x4592c9 [ 87.156397][ T8848] 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 [ 87.230734][ T8848] RSP: 002b:00007fdd63875c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1 [ 87.260046][ T8848] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004592c9 [ 87.270057][ T8848] RDX: 0000000020000600 RSI: 0000000000000001 RDI: 00007fdd63877000 [ 87.283067][ T8848] RBP: 000000000075bfc8 R08: 0000000000000000 R09: 0000000000000000 [ 87.293561][ T8848] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fdd638766d4 [ 87.306746][ T8848] R13: 00000000004c0645 R14: 00000000004d3008 R15: 00000000ffffffff 2019/06/21 21:00:39 executed programs: 15 [ 87.396396][ T3879] kobject: 'loop0' (00000000a2610baf): kobject_uevent_env [ 87.403632][ T3879] kobject: 'loop0' (00000000a2610baf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 88.348289][ T3879] kobject: 'loop0' (00000000a2610baf): kobject_uevent_env [ 88.359169][ T3879] kobject: 'loop0' (00000000a2610baf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 89.236804][ T3879] kobject: 'loop0' (00000000a2610baf): kobject_uevent_env [ 89.243991][ T3879] kobject: 'loop0' (00000000a2610baf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 90.176761][ T3879] kobject: 'loop0' (00000000a2610baf): kobject_uevent_env [ 90.184015][ T3879] kobject: 'loop0' (00000000a2610baf): fill_kobj_path: path = '/devices/virtual/block/loop0'