[....] Starting enhanced syslogd: rsyslogd[?25l[?1c7[ ok 8[?25h[?0c. [ 55.518325][ T26] audit: type=1800 audit(1561846818.334:25): pid=8563 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="cron" dev="sda1" ino=2414 res=0 [ 55.563603][ T26] audit: type=1800 audit(1561846818.334:26): pid=8563 uid=0 auid=4294967295 ses=4294967295 subj==unconfined op=collect_data cause=failed(directio) comm="startpar" name="mcstrans" dev="sda1" ino=2457 res=0 [ 55.594902][ T26] audit: type=1800 audit(1561846818.344:27): pid=8563 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.55' (ECDSA) to the list of known hosts. 2019/06/29 22:20:30 parsed 1 programs 2019/06/29 22:20:32 executed programs: 0 syzkaller login: [ 69.694457][ T8733] IPVS: ftp: loaded support on port[0] = 21 [ 69.756729][ T8733] chnl_net:caif_netlink_parms(): no params data found [ 69.783760][ T8733] bridge0: port 1(bridge_slave_0) entered blocking state [ 69.792041][ T8733] bridge0: port 1(bridge_slave_0) entered disabled state [ 69.804569][ T8733] device bridge_slave_0 entered promiscuous mode [ 69.818158][ T8733] bridge0: port 2(bridge_slave_1) entered blocking state [ 69.825770][ T8733] bridge0: port 2(bridge_slave_1) entered disabled state [ 69.836893][ T8733] device bridge_slave_1 entered promiscuous mode [ 69.871303][ T8733] bond0: (slave bond_slave_0): Enslaving as an active interface with an up link [ 69.886520][ T8733] bond0: (slave bond_slave_1): Enslaving as an active interface with an up link [ 69.908752][ T8733] team0: Port device team_slave_0 added [ 69.916196][ T8733] team0: Port device team_slave_1 added [ 69.996685][ T8733] device hsr_slave_0 entered promiscuous mode [ 70.066711][ T8733] device hsr_slave_1 entered promiscuous mode [ 70.132715][ T8733] bridge0: port 2(bridge_slave_1) entered blocking state [ 70.140726][ T8733] bridge0: port 2(bridge_slave_1) entered forwarding state [ 70.152823][ T8733] bridge0: port 1(bridge_slave_0) entered blocking state [ 70.160330][ T8733] bridge0: port 1(bridge_slave_0) entered forwarding state [ 70.195238][ T8733] 8021q: adding VLAN 0 to HW filter on device bond0 [ 70.209773][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready [ 70.223896][ T5] bridge0: port 1(bridge_slave_0) entered disabled state [ 70.234113][ T5] bridge0: port 2(bridge_slave_1) entered disabled state [ 70.243190][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready [ 70.257889][ T8733] 8021q: adding VLAN 0 to HW filter on device team0 [ 70.268348][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready [ 70.278862][ T5] bridge0: port 1(bridge_slave_0) entered blocking state [ 70.285982][ T5] bridge0: port 1(bridge_slave_0) entered forwarding state [ 70.306033][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_1: link becomes ready [ 70.316674][ T5] bridge0: port 2(bridge_slave_1) entered blocking state [ 70.327458][ T5] bridge0: port 2(bridge_slave_1) entered forwarding state [ 70.336033][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_0: link becomes ready [ 70.346201][ T5] IPv6: ADDRCONF(NETDEV_CHANGE): team_slave_1: link becomes ready [ 70.357039][ T8735] IPv6: ADDRCONF(NETDEV_CHANGE): team0: link becomes ready [ 70.371649][ T3488] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_0: link becomes ready [ 70.386023][ T8733] hsr0: Slave B (hsr_slave_1) is not up; please bring it up to get a fully working HSR network [ 70.398971][ T8733] IPv6: ADDRCONF(NETDEV_CHANGE): hsr0: link becomes ready [ 70.407909][ T2875] IPv6: ADDRCONF(NETDEV_CHANGE): hsr_slave_1: link becomes ready [ 70.427100][ T8733] 8021q: adding VLAN 0 to HW filter on device batadv0 2019/06/29 22:20:38 executed programs: 5 2019/06/29 22:20:43 executed programs: 11 [ 83.523189][ T8809] [ 83.537417][ T8809] ===================================================== [ 83.553342][ T8809] WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected [ 83.561404][ T8809] 5.2.0-rc6-next-20190628 #25 Not tainted [ 83.569716][ T8809] ----------------------------------------------------- [ 83.584060][ T8809] syz-executor.0/8809 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire: [ 83.629407][ T8809] 00000000d4f49108 (&ctx->fd_wqh){....}, at: io_submit_one+0xefa/0x2ef0 [ 83.648851][ T8809] [ 83.648851][ T8809] and this task is already holding: [ 83.665102][ T8809] 000000000aaf2a8b (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 83.696731][ T8809] which would create a new lock dependency: [ 83.723021][ T8809] (&(&ctx->ctx_lock)->rlock){..-.} -> (&ctx->fd_wqh){....} [ 83.735415][ T8809] [ 83.735415][ T8809] but this new dependency connects a SOFTIRQ-irq-safe lock: [ 83.748515][ T8809] (&(&ctx->ctx_lock)->rlock){..-.} [ 83.748526][ T8809] [ 83.748526][ T8809] ... which became SOFTIRQ-irq-safe at: [ 83.771029][ T8809] lock_acquire+0x190/0x410 [ 83.777401][ T8809] _raw_spin_lock_irq+0x60/0x80 [ 83.782347][ T8809] free_ioctx_users+0x2d/0x490 [ 83.789628][ T8809] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 83.795877][ T8809] rcu_core+0x67f/0x1580 [ 83.800462][ T8809] rcu_core_si+0x9/0x10 [ 83.808970][ T8809] __do_softirq+0x262/0x98c [ 83.814370][ T8809] irq_exit+0x19b/0x1e0 [ 83.823633][ T8809] smp_apic_timer_interrupt+0x1a3/0x610 [ 83.830350][ T8809] apic_timer_interrupt+0xf/0x20 [ 83.836571][ T8809] native_safe_halt+0xe/0x10 [ 83.842115][ T8809] arch_cpu_idle+0xa/0x10 [ 83.850511][ T8809] default_idle_call+0x84/0xb0 [ 83.859130][ T8809] do_idle+0x413/0x760 [ 83.868353][ T8809] cpu_startup_entry+0x1b/0x20 [ 83.874333][ T8809] start_secondary+0x3fe/0x580 [ 83.881981][ T8809] secondary_startup_64+0xa4/0xb0 [ 83.887446][ T8809] [ 83.887446][ T8809] to a SOFTIRQ-irq-unsafe lock: [ 83.894896][ T8809] (&ctx->fault_pending_wqh){+.+.} [ 83.894905][ T8809] [ 83.894905][ T8809] ... which became SOFTIRQ-irq-unsafe at: [ 83.920223][ T8809] ... [ 83.920242][ T8809] lock_acquire+0x190/0x410 [ 83.932464][ T8809] _raw_spin_lock+0x2f/0x40 [ 83.937203][ T8809] userfaultfd_release+0x4ca/0x710 [ 83.943026][ T8809] __fput+0x2ff/0x890 [ 83.947280][ T8809] ____fput+0x16/0x20 [ 83.952621][ T8809] task_work_run+0x145/0x1c0 [ 83.957524][ T8809] get_signal+0x2078/0x2500 [ 83.962228][ T8809] do_signal+0x87/0x1700 [ 83.967885][ T8809] exit_to_usermode_loop+0x251/0x2d0 [ 83.973820][ T8809] do_syscall_64+0x5a9/0x6a0 [ 83.978613][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 83.984833][ T8809] [ 83.984833][ T8809] other info that might help us debug this: [ 83.984833][ T8809] [ 83.995135][ T8809] Chain exists of: [ 83.995135][ T8809] &(&ctx->ctx_lock)->rlock --> &ctx->fd_wqh --> &ctx->fault_pending_wqh [ 83.995135][ T8809] [ 84.009429][ T8809] Possible interrupt unsafe locking scenario: [ 84.009429][ T8809] [ 84.017823][ T8809] CPU0 CPU1 [ 84.023690][ T8809] ---- ---- [ 84.029110][ T8809] lock(&ctx->fault_pending_wqh); [ 84.034317][ T8809] local_irq_disable(); [ 84.041195][ T8809] lock(&(&ctx->ctx_lock)->rlock); [ 84.049139][ T8809] lock(&ctx->fd_wqh); [ 84.055802][ T8809] [ 84.059356][ T8809] lock(&(&ctx->ctx_lock)->rlock); [ 84.064757][ T8809] [ 84.064757][ T8809] *** DEADLOCK *** [ 84.064757][ T8809] [ 84.072922][ T8809] 1 lock held by syz-executor.0/8809: [ 84.078435][ T8809] #0: 000000000aaf2a8b (&(&ctx->ctx_lock)->rlock){..-.}, at: io_submit_one+0xeb5/0x2ef0 [ 84.088480][ T8809] [ 84.088480][ T8809] the dependencies between SOFTIRQ-irq-safe lock and the holding lock: [ 84.098985][ T8809] -> (&(&ctx->ctx_lock)->rlock){..-.} { [ 84.104967][ T8809] IN-SOFTIRQ-W at: [ 84.109061][ T8809] lock_acquire+0x190/0x410 [ 84.115315][ T8809] _raw_spin_lock_irq+0x60/0x80 [ 84.121952][ T8809] free_ioctx_users+0x2d/0x490 [ 84.128627][ T8809] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 84.136907][ T8809] rcu_core+0x67f/0x1580 [ 84.143024][ T8809] rcu_core_si+0x9/0x10 [ 84.149490][ T8809] __do_softirq+0x262/0x98c [ 84.155793][ T8809] irq_exit+0x19b/0x1e0 [ 84.161650][ T8809] smp_apic_timer_interrupt+0x1a3/0x610 [ 84.168934][ T8809] apic_timer_interrupt+0xf/0x20 [ 84.175774][ T8809] native_safe_halt+0xe/0x10 [ 84.182854][ T8809] arch_cpu_idle+0xa/0x10 [ 84.189379][ T8809] default_idle_call+0x84/0xb0 [ 84.196065][ T8809] do_idle+0x413/0x760 [ 84.202285][ T8809] cpu_startup_entry+0x1b/0x20 [ 84.208715][ T8809] start_secondary+0x3fe/0x580 [ 84.215308][ T8809] secondary_startup_64+0xa4/0xb0 [ 84.222086][ T8809] INITIAL USE at: [ 84.225982][ T8809] lock_acquire+0x190/0x410 [ 84.232161][ T8809] _raw_spin_lock_irq+0x60/0x80 [ 84.238892][ T8809] free_ioctx_users+0x2d/0x490 [ 84.245651][ T8809] percpu_ref_switch_to_atomic_rcu+0x4c0/0x570 [ 84.253862][ T8809] rcu_core+0x67f/0x1580 [ 84.259675][ T8809] rcu_core_si+0x9/0x10 [ 84.265495][ T8809] __do_softirq+0x262/0x98c [ 84.271563][ T8809] irq_exit+0x19b/0x1e0 [ 84.277411][ T8809] smp_apic_timer_interrupt+0x1a3/0x610 [ 84.284928][ T8809] apic_timer_interrupt+0xf/0x20 [ 84.291548][ T8809] native_safe_halt+0xe/0x10 [ 84.297808][ T8809] arch_cpu_idle+0xa/0x10 [ 84.303723][ T8809] default_idle_call+0x84/0xb0 [ 84.310515][ T8809] do_idle+0x413/0x760 [ 84.316228][ T8809] cpu_startup_entry+0x1b/0x20 [ 84.323180][ T8809] start_secondary+0x3fe/0x580 [ 84.329859][ T8809] secondary_startup_64+0xa4/0xb0 [ 84.336632][ T8809] } [ 84.339332][ T8809] ... key at: [] __key.53845+0x0/0x40 [ 84.347423][ T8809] ... acquired at: [ 84.351241][ T8809] lock_acquire+0x190/0x410 [ 84.355963][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.360655][ T8809] io_submit_one+0xefa/0x2ef0 [ 84.365504][ T8809] __x64_sys_io_submit+0x1bd/0x570 [ 84.370776][ T8809] do_syscall_64+0xfd/0x6a0 [ 84.375439][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.381589][ T8809] [ 84.384099][ T8809] [ 84.384099][ T8809] the dependencies between the lock to be acquired [ 84.384110][ T8809] and SOFTIRQ-irq-unsafe lock: [ 84.397637][ T8809] -> (&ctx->fault_pending_wqh){+.+.} { [ 84.403485][ T8809] HARDIRQ-ON-W at: [ 84.407614][ T8809] lock_acquire+0x190/0x410 [ 84.414716][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.421064][ T8809] userfaultfd_release+0x4ca/0x710 [ 84.428130][ T8809] __fput+0x2ff/0x890 [ 84.434314][ T8809] ____fput+0x16/0x20 [ 84.440276][ T8809] task_work_run+0x145/0x1c0 [ 84.446756][ T8809] get_signal+0x2078/0x2500 [ 84.453269][ T8809] do_signal+0x87/0x1700 [ 84.459472][ T8809] exit_to_usermode_loop+0x251/0x2d0 [ 84.466798][ T8809] do_syscall_64+0x5a9/0x6a0 [ 84.474041][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.482515][ T8809] SOFTIRQ-ON-W at: [ 84.486768][ T8809] lock_acquire+0x190/0x410 [ 84.493576][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.499914][ T8809] userfaultfd_release+0x4ca/0x710 [ 84.508857][ T8809] __fput+0x2ff/0x890 [ 84.514762][ T8809] ____fput+0x16/0x20 [ 84.522418][ T8809] task_work_run+0x145/0x1c0 [ 84.530514][ T8809] get_signal+0x2078/0x2500 [ 84.536904][ T8809] do_signal+0x87/0x1700 [ 84.542987][ T8809] exit_to_usermode_loop+0x251/0x2d0 [ 84.550102][ T8809] do_syscall_64+0x5a9/0x6a0 [ 84.557118][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.564823][ T8809] INITIAL USE at: [ 84.568892][ T8809] lock_acquire+0x190/0x410 [ 84.575680][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.581913][ T8809] userfaultfd_read+0x54d/0x1940 [ 84.590788][ T8809] __vfs_read+0x8a/0x110 [ 84.596780][ T8809] vfs_read+0x1f0/0x440 [ 84.603199][ T8809] ksys_read+0x14f/0x290 [ 84.610818][ T8809] __x64_sys_read+0x73/0xb0 [ 84.621214][ T8809] do_syscall_64+0xfd/0x6a0 [ 84.630095][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.638987][ T8809] } [ 84.641605][ T8809] ... key at: [] __key.46557+0x0/0x40 [ 84.649539][ T8809] ... acquired at: [ 84.653528][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.658635][ T8809] userfaultfd_read+0x54d/0x1940 [ 84.664578][ T8809] __vfs_read+0x8a/0x110 [ 84.669632][ T8809] vfs_read+0x1f0/0x440 [ 84.674155][ T8809] ksys_read+0x14f/0x290 [ 84.680467][ T8809] __x64_sys_read+0x73/0xb0 [ 84.687212][ T8809] do_syscall_64+0xfd/0x6a0 [ 84.692806][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.704673][ T8809] [ 84.707666][ T8809] -> (&ctx->fd_wqh){....} { [ 84.714178][ T8809] INITIAL USE at: [ 84.723797][ T8809] lock_acquire+0x190/0x410 [ 84.732034][ T8809] _raw_spin_lock_irq+0x60/0x80 [ 84.740299][ T8809] userfaultfd_read+0x27a/0x1940 [ 84.749205][ T8809] __vfs_read+0x8a/0x110 [ 84.755669][ T8809] vfs_read+0x1f0/0x440 [ 84.761597][ T8809] ksys_read+0x14f/0x290 [ 84.768024][ T8809] __x64_sys_read+0x73/0xb0 [ 84.774780][ T8809] do_syscall_64+0xfd/0x6a0 [ 84.782692][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.792346][ T8809] } [ 84.795152][ T8809] ... key at: [] __key.46560+0x0/0x40 [ 84.805681][ T8809] ... acquired at: [ 84.809514][ T8809] lock_acquire+0x190/0x410 [ 84.815133][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.820442][ T8809] io_submit_one+0xefa/0x2ef0 [ 84.825308][ T8809] __x64_sys_io_submit+0x1bd/0x570 [ 84.831262][ T8809] do_syscall_64+0xfd/0x6a0 [ 84.836244][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 84.842505][ T8809] [ 84.844999][ T8809] [ 84.844999][ T8809] stack backtrace: [ 84.853614][ T8809] CPU: 0 PID: 8809 Comm: syz-executor.0 Not tainted 5.2.0-rc6-next-20190628 #25 [ 84.867204][ T8809] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 [ 84.880717][ T8809] Call Trace: [ 84.884044][ T8809] dump_stack+0x172/0x1f0 [ 84.891794][ T8809] check_irq_usage.cold+0x5b4/0x72e [ 84.898613][ T8809] ? check_usage_forwards+0x330/0x330 [ 84.904014][ T8809] ? check_path+0x26/0x40 [ 84.909020][ T8809] ? kasan_check_read+0x11/0x20 [ 84.914090][ T8809] ? check_noncircular+0x16a/0x3e0 [ 84.919200][ T8809] ? print_circular_bug+0x200/0x200 [ 84.925586][ T8809] ? __lockdep_reset_lock+0x450/0x450 [ 84.932714][ T8809] ? __sanitizer_cov_trace_const_cmp8+0x18/0x20 [ 84.939828][ T8809] __lock_acquire+0x25bd/0x4c20 [ 84.944881][ T8809] ? __lock_acquire+0x25bd/0x4c20 [ 84.950244][ T8809] ? mark_held_locks+0xf0/0xf0 [ 84.955102][ T8809] ? trace_hardirqs_on+0x67/0x240 [ 84.962010][ T8809] ? kasan_check_read+0x11/0x20 [ 84.967434][ T8809] lock_acquire+0x190/0x410 [ 84.972155][ T8809] ? io_submit_one+0xefa/0x2ef0 [ 84.977713][ T8809] _raw_spin_lock+0x2f/0x40 [ 84.982655][ T8809] ? io_submit_one+0xefa/0x2ef0 [ 84.987521][ T8809] io_submit_one+0xefa/0x2ef0 [ 84.992222][ T8809] ? lookup_ioctx+0x1d7/0x830 [ 84.997733][ T8809] ? ioctx_alloc+0x1dc0/0x1dc0 [ 85.003840][ T8809] ? aio_setup_rw+0x180/0x180 [ 85.008655][ T8809] __x64_sys_io_submit+0x1bd/0x570 [ 85.013875][ T8809] ? __x64_sys_io_submit+0x1bd/0x570 [ 85.019471][ T8809] ? __ia32_sys_io_destroy+0x420/0x420 [ 85.025067][ T8809] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 85.031922][ T8809] ? trace_hardirqs_on_thunk+0x1a/0x1c [ 85.038060][ T8809] ? do_syscall_64+0x26/0x6a0 [ 85.043016][ T8809] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 85.049531][ T8809] ? do_syscall_64+0x26/0x6a0 [ 85.054872][ T8809] ? lockdep_hardirqs_on+0x418/0x5d0 [ 85.060965][ T8809] do_syscall_64+0xfd/0x6a0 [ 85.066987][ T8809] ? do_syscall_64+0xfd/0x6a0 [ 85.071837][ T8809] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 85.078159][ T8809] RIP: 0033:0x459519 [ 85.082346][ T8809] 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 [ 85.102565][ T8809] RSP: 002b:00007fc0202bac78 EFLAGS: 00000246 ORIG_RAX: 00000000000000d1 [ 85.110993][ T8809] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000459519 [ 85.119891][ T8809] RDX: 0000000020000600 RSI: 0000000000000001 RDI: 00007fc0202bc000 [ 85.128188][ T8809] RBP: 000000000075bfc8 R08: 0000000000000000 R09: 0000000000000000 [ 85.136168][ T8809] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fc0202bb6d4 [ 85.144748][ T8809] R13: 00000000004c0898 R14: 00000000004d3548 R15: 00000000ffffffff [ 85.281088][ T3879] kobject: 'loop0' (00000000afe25aaf): kobject_uevent_env [ 85.293291][ T3879] kobject: 'loop0' (00000000afe25aaf): fill_kobj_path: path = '/devices/virtual/block/loop0' 2019/06/29 22:20:49 executed programs: 15 [ 86.221413][ T3879] kobject: 'loop0' (00000000afe25aaf): kobject_uevent_env [ 86.228936][ T3879] kobject: 'loop0' (00000000afe25aaf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 87.111198][ T3879] kobject: 'loop0' (00000000afe25aaf): kobject_uevent_env [ 87.118434][ T3879] kobject: 'loop0' (00000000afe25aaf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 88.010510][ T3879] kobject: 'loop0' (00000000afe25aaf): kobject_uevent_env [ 88.018449][ T3879] kobject: 'loop0' (00000000afe25aaf): fill_kobj_path: path = '/devices/virtual/block/loop0' [ 88.951494][ T3879] kobject: 'loop0' (00000000afe25aaf): kobject_uevent_env [ 88.959476][ T3879] kobject: 'loop0' (00000000afe25aaf): fill_kobj_path: path = '/devices/virtual/block/loop0'