[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 61.355981][ T27] audit: type=1800 audit(1562310459.970:25): pid=9074 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 61.399184][ T27] audit: type=1800 audit(1562310459.980:26): pid=9074 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 61.454800][ T27] audit: type=1800 audit(1562310459.980:27): pid=9074 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.10.24' (ECDSA) to the list of known hosts. 2019/07/05 07:07:52 parsed 1 programs 2019/07/05 07:07:54 executed programs: 0 syzkaller login: [ 76.008576][ T9242] IPVS: ftp: loaded support on port[0] = 21 [ 76.075149][ T9242] chnl_net:caif_netlink_parms(): no params data found [ 76.108175][ T9242] bridge0: port 1(bridge_slave_0) entered blocking state [ 76.116524][ T9242] bridge0: port 1(bridge_slave_0) entered disabled state [ 76.124634][ T9242] device bridge_slave_0 entered promiscuous mode [ 76.132819][ T9242] bridge0: port 2(bridge_slave_1) entered blocking state [ 76.140304][ T9242] bridge0: port 2(bridge_slave_1) entered disabled state [ 76.148220][ T9242] device bridge_slave_1 entered promiscuous mode [ 76.166271][ T9242] bond0: (slave bond_slave_0): Enslaving as an active interface with an up link [ 76.177619][ T9242] bond0: (slave bond_slave_1): Enslaving as an active interface with an up link [ 76.197505][ T9242] team0: Port device team_slave_0 added [ 76.205283][ T9242] team0: Port device team_slave_1 added [ 76.291141][ T9242] device hsr_slave_0 entered promiscuous mode [ 76.339734][ T9242] device hsr_slave_1 entered promiscuous mode [ 76.417163][ T9242] bridge0: port 2(bridge_slave_1) entered blocking state [ 76.424893][ T9242] bridge0: port 2(bridge_slave_1) entered forwarding state [ 76.433034][ T9242] bridge0: port 1(bridge_slave_0) entered blocking state [ 76.441125][ T9242] bridge0: port 1(bridge_slave_0) entered forwarding state [ 76.476617][ T9242] 8021q: adding VLAN 0 to HW filter on device bond0 [ 76.491642][ T22] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 76.502603][ T22] bridge0: port 1(bridge_slave_0) entered disabled state [ 76.511145][ T22] bridge0: port 2(bridge_slave_1) entered disabled state [ 76.519373][ T22] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 76.531744][ T9242] 8021q: adding VLAN 0 to HW filter on device team0 [ 76.542970][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 76.552570][ T2857] bridge0: port 1(bridge_slave_0) entered blocking state [ 76.560529][ T2857] bridge0: port 1(bridge_slave_0) entered forwarding state [ 76.582372][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 76.592910][ T2857] bridge0: port 2(bridge_slave_1) entered blocking state [ 76.600808][ T2857] bridge0: port 2(bridge_slave_1) entered forwarding state [ 76.610163][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 76.619659][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 76.629592][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 76.641405][ T9244] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 76.654180][ T9242] hsr0: Slave B (hsr_slave_1) is not up; please bring it up to get a fully working HSR network [ 76.666972][ T9242] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 76.675313][ T2857] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 76.697329][ T9242] 8021q: adding VLAN 0 to HW filter on device batadv0 2019/07/05 07:08:00 executed programs: 5 2019/07/05 07:08:05 executed programs: 11 [ 89.741120][ T9319] [ 89.743498][ T9319] ===================================================== [ 89.750414][ T9319] WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected [ 89.757854][ T9319] 5.2.0-rc7-next-20190703 #28 Not tainted [ 89.763647][ T9319] ----------------------------------------------------- [ 89.770564][ T9319] syz-executor.0/9319 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 89.778516][ T9319] 00000000a1e6d529 (&ctx->fd_wqh){....}, at: io_submit_one+0xefa/0x2ef0 [ 89.786863][ T9319] [ 89.786863][ T9319] and this task is already holding: [ 89.794246][ T9319] 0000000035fac755 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 89.803662][ T9319] which would create a new lock dependency: [ 89.809531][ T9319] (&(&ctx->ctx_lock)->rlock){..-.} -> (&ctx->fd_wqh){....} [ 89.816800][ T9319] [ 89.816800][ T9319] but this new dependency connects a SOFTIRQ-irq-safe lock: [ 89.826264][ T9319] (&(&ctx->ctx_lock)->rlock){..-.} [ 89.826272][ T9319] [ 89.826272][ T9319] ... which became SOFTIRQ-irq-safe at: [ 89.839241][ T9319] lock_acquire+0x190/0x410 [ 89.843811][ T9319] _raw_spin_lock_irq+0x60/0x80 [ 89.848731][ T9319] free_ioctx_users+0x2d/0x490 [ 89.853661][ T9319] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 89.859883][ T9319] rcu_core+0x67f/0x1580 [ 89.864247][ T9319] rcu_core_si+0x9/0x10 [ 89.868474][ T9319] __do_softirq+0x262/0x98c [ 89.873047][ T9319] irq_exit+0x19b/0x1e0 [ 89.877266][ T9319] smp_apic_timer_interrupt+0x1a3/0x610 [ 89.882878][ T9319] apic_timer_interrupt+0xf/0x20 [ 89.887877][ T9319] native_safe_halt+0xe/0x10 [ 89.892542][ T9319] arch_cpu_idle+0xa/0x10 [ 89.897033][ T9319] default_idle_call+0x84/0xb0 [ 89.901873][ T9319] do_idle+0x413/0x760 [ 89.906104][ T9319] cpu_startup_entry+0x1b/0x20 [ 89.910943][ T9319] start_secondary+0x3fe/0x580 [ 89.915776][ T9319] secondary_startup_64+0xa4/0xb0 [ 89.920904][ T9319] [ 89.920904][ T9319] to a SOFTIRQ-irq-unsafe lock: [ 89.928138][ T9319] (&ctx->fault_pending_wqh){+.+.} [ 89.928146][ T9319] [ 89.928146][ T9319] ... which became SOFTIRQ-irq-unsafe at: [ 89.941090][ T9319] ... [ 89.941106][ T9319] lock_acquire+0x190/0x410 [ 89.948242][ T9319] _raw_spin_lock+0x2f/0x40 [ 89.952812][ T9319] userfaultfd_release+0x4ca/0x710 [ 89.958001][ T9319] __fput+0x2ff/0x890 [ 89.962066][ T9319] ____fput+0x16/0x20 [ 89.966116][ T9319] task_work_run+0x145/0x1c0 [ 89.970814][ T9319] get_signal+0x2078/0x2500 [ 89.975386][ T9319] do_signal+0x87/0x1700 [ 89.979689][ T9319] exit_to_usermode_loop+0x251/0x2d0 [ 89.985190][ T9319] do_syscall_64+0x5a9/0x6a0 [ 89.989851][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 89.995800][ T9319] [ 89.995800][ T9319] other info that might help us debug this: [ 89.995800][ T9319] [ 90.006095][ T9319] Chain exists of: [ 90.006095][ T9319] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 90.006095][ T9319] [ 90.020306][ T9319] Possible interrupt unsafe locking scenario: [ 90.020306][ T9319] [ 90.028604][ T9319] CPU0 CPU1 [ 90.033947][ T9319] ---- ---- [ 90.039321][ T9319] lock(&ctx->fault_pending_wqh); [ 90.044413][ T9319] local_irq_disable(); [ 90.051151][ T9319] lock(&(&ctx->ctx_lock)->rlock); [ 90.058841][ T9319] lock(&ctx->fd_wqh); [ 90.065491][ T9319] [ 90.068934][ T9319] lock(&(&ctx->ctx_lock)->rlock); [ 90.074290][ T9319] [ 90.074290][ T9319] *** DEADLOCK *** [ 90.074290][ T9319] [ 90.082711][ T9319] 1 lock held by syz-executor.0/9319: [ 90.088626][ T9319] #0: 0000000035fac755 (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 90.098470][ T9319] [ 90.098470][ T9319] the dependencies between SOFTIRQ-irq-safe lock and the holding lock: [ 90.108969][ T9319] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 90.114515][ T9319] IN-SOFTIRQ-W at: [ 90.118490][ T9319] lock_acquire+0x190/0x410 [ 90.124630][ T9319] _raw_spin_lock_irq+0x60/0x80 [ 90.131110][ T9319] free_ioctx_users+0x2d/0x490 [ 90.137512][ T9319] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 90.145741][ T9319] rcu_core+0x67f/0x1580 [ 90.151958][ T9319] rcu_core_si+0x9/0x10 [ 90.157748][ T9319] __do_softirq+0x262/0x98c [ 90.163895][ T9319] irq_exit+0x19b/0x1e0 [ 90.169677][ T9319] smp_apic_timer_interrupt+0x1a3/0x610 [ 90.176888][ T9319] apic_timer_interrupt+0xf/0x20 [ 90.183467][ T9319] native_safe_halt+0xe/0x10 [ 90.189758][ T9319] arch_cpu_idle+0xa/0x10 [ 90.195758][ T9319] default_idle_call+0x84/0xb0 [ 90.202162][ T9319] do_idle+0x413/0x760 [ 90.207863][ T9319] cpu_startup_entry+0x1b/0x20 [ 90.214253][ T9319] start_secondary+0x3fe/0x580 [ 90.220707][ T9319] secondary_startup_64+0xa4/0xb0 [ 90.227484][ T9319] INITIAL USE at: [ 90.231363][ T9319] lock_acquire+0x190/0x410 [ 90.237534][ T9319] _raw_spin_lock_irq+0x60/0x80 [ 90.243931][ T9319] free_ioctx_users+0x2d/0x490 [ 90.250279][ T9319] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 90.257980][ T9319] rcu_core+0x67f/0x1580 [ 90.263769][ T9319] rcu_core_si+0x9/0x10 [ 90.269728][ T9319] __do_softirq+0x262/0x98c [ 90.275782][ T9319] irq_exit+0x19b/0x1e0 [ 90.281484][ T9319] smp_apic_timer_interrupt+0x1a3/0x610 [ 90.288670][ T9319] apic_timer_interrupt+0xf/0x20 [ 90.295153][ T9319] native_safe_halt+0xe/0x10 [ 90.301374][ T9319] arch_cpu_idle+0xa/0x10 [ 90.307252][ T9319] default_idle_call+0x84/0xb0 [ 90.313557][ T9319] do_idle+0x413/0x760 [ 90.319166][ T9319] cpu_startup_entry+0x1b/0x20 [ 90.325483][ T9319] start_secondary+0x3fe/0x580 [ 90.331976][ T9319] secondary_startup_64+0xa4/0xb0 [ 90.338542][ T9319] } [ 90.341106][ T9319] ... key at: [] __key.53855+0x0/0x40 [ 90.348720][ T9319] ... acquired at: [ 90.352556][ T9319] lock_acquire+0x190/0x410 [ 90.357222][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.361930][ T9319] io_submit_one+0xefa/0x2ef0 [ 90.366926][ T9319] __x64_sys_io_submit+0x1bd/0x570 [ 90.372201][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.377039][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.383191][ T9319] [ 90.385499][ T9319] [ 90.385499][ T9319] the dependencies between the lock to be acquired [ 90.385502][ T9319] and SOFTIRQ-irq-unsafe lock: [ 90.398976][ T9319] -> (&ctx->fault_pending_wqh){+.+.} { [ 90.404504][ T9319] HARDIRQ-ON-W at: [ 90.408703][ T9319] lock_acquire+0x190/0x410 [ 90.415025][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.421405][ T9319] userfaultfd_release+0x4ca/0x710 [ 90.428332][ T9319] __fput+0x2ff/0x890 [ 90.434144][ T9319] ____fput+0x16/0x20 [ 90.440085][ T9319] task_work_run+0x145/0x1c0 [ 90.446480][ T9319] get_signal+0x2078/0x2500 [ 90.452779][ T9319] do_signal+0x87/0x1700 [ 90.458834][ T9319] exit_to_usermode_loop+0x251/0x2d0 [ 90.465927][ T9319] do_syscall_64+0x5a9/0x6a0 [ 90.472351][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.480034][ T9319] SOFTIRQ-ON-W at: [ 90.484467][ T9319] lock_acquire+0x190/0x410 [ 90.490813][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.497124][ T9319] userfaultfd_release+0x4ca/0x710 [ 90.504039][ T9319] __fput+0x2ff/0x890 [ 90.509879][ T9319] ____fput+0x16/0x20 [ 90.515705][ T9319] task_work_run+0x145/0x1c0 [ 90.522104][ T9319] get_signal+0x2078/0x2500 [ 90.528419][ T9319] do_signal+0x87/0x1700 [ 90.534466][ T9319] exit_to_usermode_loop+0x251/0x2d0 [ 90.541553][ T9319] do_syscall_64+0x5a9/0x6a0 [ 90.547942][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.555627][ T9319] INITIAL USE at: [ 90.559594][ T9319] lock_acquire+0x190/0x410 [ 90.565815][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.572028][ T9319] userfaultfd_read+0x54d/0x1940 [ 90.578674][ T9319] __vfs_read+0x8a/0x110 [ 90.584645][ T9319] vfs_read+0x1f0/0x440 [ 90.590527][ T9319] ksys_read+0x14f/0x290 [ 90.596533][ T9319] __x64_sys_read+0x73/0xb0 [ 90.602764][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.609091][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.616691][ T9319] } [ 90.619262][ T9319] ... key at: [] __key.46572+0x0/0x40 [ 90.626770][ T9319] ... acquired at: [ 90.630703][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.635370][ T9319] userfaultfd_read+0x54d/0x1940 [ 90.640461][ T9319] __vfs_read+0x8a/0x110 [ 90.644898][ T9319] vfs_read+0x1f0/0x440 [ 90.649222][ T9319] ksys_read+0x14f/0x290 [ 90.653617][ T9319] __x64_sys_read+0x73/0xb0 [ 90.658268][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.663047][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.669170][ T9319] [ 90.671480][ T9319] -> (&ctx->fd_wqh){....} { [ 90.675971][ T9319] INITIAL USE at: [ 90.679846][ T9319] lock_acquire+0x190/0x410 [ 90.685950][ T9319] _raw_spin_lock_irq+0x60/0x80 [ 90.692350][ T9319] userfaultfd_read+0x27a/0x1940 [ 90.698865][ T9319] __vfs_read+0x8a/0x110 [ 90.704686][ T9319] vfs_read+0x1f0/0x440 [ 90.710427][ T9319] ksys_read+0x14f/0x290 [ 90.716304][ T9319] __x64_sys_read+0x73/0xb0 [ 90.722347][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.728490][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.735915][ T9319] } [ 90.738404][ T9319] ... key at: [] __key.46575+0x0/0x40 [ 90.745831][ T9319] ... acquired at: [ 90.749619][ T9319] lock_acquire+0x190/0x410 [ 90.754269][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.758919][ T9319] io_submit_one+0xefa/0x2ef0 [ 90.763748][ T9319] __x64_sys_io_submit+0x1bd/0x570 [ 90.769109][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.773764][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.779799][ T9319] [ 90.782104][ T9319] [ 90.782104][ T9319] stack backtrace: [ 90.787976][ T9319] CPU: 0 PID: 9319 Comm: syz-executor.0 Not tainted 5.2.0-rc7-next-20190703 #28 [ 90.796970][ T9319] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 90.807104][ T9319] Call Trace: [ 90.810602][ T9319] dump_stack+0x172/0x1f0 [ 90.814954][ T9319] check_irq_usage.cold+0x5b4/0x72e [ 90.820177][ T9319] ? check_usage_forwards+0x330/0x330 [ 90.825631][ T9319] ? check_path+0x26/0x40 [ 90.829943][ T9319] ? kasan_check_read+0x11/0x20 [ 90.834777][ T9319] ? check_noncircular+0x16a/0x3e0 [ 90.839910][ T9319] ? print_circular_bug+0x200/0x200 [ 90.845220][ T9319] ? __lockdep_reset_lock+0x450/0x450 [ 90.850672][ T9319] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 90.856950][ T9319] __lock_acquire+0x25bd/0x4c20 [ 90.861922][ T9319] ? __lock_acquire+0x25bd/0x4c20 [ 90.866936][ T9319] ? mark_held_locks+0xf0/0xf0 [ 90.871688][ T9319] ? trace_hardirqs_on+0x67/0x240 [ 90.876689][ T9319] ? kasan_check_read+0x11/0x20 [ 90.881648][ T9319] lock_acquire+0x190/0x410 [ 90.886143][ T9319] ? io_submit_one+0xefa/0x2ef0 [ 90.891068][ T9319] _raw_spin_lock+0x2f/0x40 [ 90.895554][ T9319] ? io_submit_one+0xefa/0x2ef0 [ 90.900399][ T9319] io_submit_one+0xefa/0x2ef0 [ 90.905204][ T9319] ? lookup_ioctx+0x1d7/0x830 [ 90.910191][ T9319] ? ioctx_alloc+0x1dc0/0x1dc0 [ 90.914986][ T9319] ? aio_setup_rw+0x180/0x180 [ 90.920690][ T9319] __x64_sys_io_submit+0x1bd/0x570 [ 90.925791][ T9319] ? __x64_sys_io_submit+0x1bd/0x570 [ 90.931105][ T9319] ? __ia32_sys_io_destroy+0x420/0x420 [ 90.936566][ T9319] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 90.942197][ T9319] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 90.947647][ T9319] ? do_syscall_64+0x26/0x6a0 [ 90.952414][ T9319] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.958473][ T9319] ? do_syscall_64+0x26/0x6a0 [ 90.963198][ T9319] ? lockdep_hardirqs_on+0x418/0x5d0 [ 90.968554][ T9319] do_syscall_64+0xfd/0x6a0 [ 90.973076][ T9319] ? do_syscall_64+0xfd/0x6a0 [ 90.977742][ T9319] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 90.983655][ T9319] RIP: 0033:0x4597c9 [ 90.987542][ T9319] 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 [ 91.007236][ T9319] RSP: 002b:00007fb738153c78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1 [ 91.015636][ T9319] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004597c9 [ 91.023604][ T9319] RDX: 0000000020000600 RSI: 0000000000000001 RDI: 00007fb738155000 [ 91.031572][ T9319] RBP: 000000000075bfc8 R08: 0000000000000000 R09: 0000000000000000 [ 91.039623][ T9319] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fb7381546d4 [ 91.047678][ T9319] R13: 00000000004c0b97 R14: 00000000004d3908 R15: 00000000ffffffff [ 91.125188][ T3878] kobject: 'loop0' (00000000c7c2657e): kobject_uevent_env [ 91.132438][ T3878] kobject: 'loop0' (00000000c7c2657e): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 92.004931][ T3878] kobject: 'loop0' (00000000c7c2657e): kobject_uevent_env [ 92.012736][ T3878] kobject: 'loop0' (00000000c7c2657e): fill_kobj_path: path = '/devices/virtual/block/loop0' 2019/07/05 07:08:11 executed programs: 16 [ 92.945299][ T3878] kobject: 'loop0' (00000000c7c2657e): kobject_uevent_env [ 92.953262][ T3878] kobject: 'loop0' (00000000c7c2657e): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 93.883770][ T3878] kobject: 'loop0' (00000000c7c2657e): kobject_uevent_env [ 93.891229][ T3878] kobject: 'loop0' (00000000c7c2657e): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 94.785236][ T3878] kobject: 'loop0' (00000000c7c2657e): kobject_uevent_env [ 94.792550][ T3878] kobject: 'loop0' (00000000c7c2657e): fill_kobj_path: path = '/devices/virtual/block/loop0'